PPPD keeps resetting

I have been on 22.03.6 and didn't have any similar problems with it but since I've switched to 23.05.3 (0/1/2 also tested) my PPPoE connection drops randomly as seen in below log

Wed May 22 19:37:55 2024 kern.info kernel: [ 8598.610632] igc 0000:03:00.0 eth2: NIC Link is Down
Wed May 22 19:37:55 2024 kern.info kernel: [ 8598.616588] br-lan: port 3(eth2) entered disabled state
Wed May 22 19:37:55 2024 daemon.notice netifd: Network device 'eth2' link is down
Wed May 22 19:37:55 2024 daemon.notice netifd: 8021q 'eth2.6' link is down
Wed May 22 19:37:55 2024 daemon.notice netifd: Interface 'wan' has link connectivity loss
Wed May 22 19:38:00 2024 kern.info kernel: [ 8602.840811] igc 0000:03:00.0 eth2: NIC Link is Up 2500 Mbps Full Duplex, Flow Control: RX
Wed May 22 19:38:00 2024 kern.info kernel: [ 8602.849675] br-lan: port 3(eth2) entered blocking state
Wed May 22 19:38:00 2024 kern.info kernel: [ 8602.855208] br-lan: port 3(eth2) entered forwarding state
Wed May 22 19:38:00 2024 daemon.notice netifd: Network device 'eth2' link is up
Wed May 22 19:38:00 2024 daemon.notice netifd: 8021q 'eth2.6' link is up
Wed May 22 19:38:00 2024 daemon.notice netifd: Interface 'wan' has link connectivity
Wed May 22 19:38:27 2024 daemon.info pppd[5890]: No response to 5 echo-requests
Wed May 22 19:38:27 2024 daemon.notice pppd[5890]: Serial link appears to be disconnected.
Wed May 22 19:38:27 2024 daemon.info pppd[5890]: Connect time 14.2 minutes.
Wed May 22 19:38:27 2024 daemon.info pppd[5890]: Sent 6087000 bytes, received 98463578 bytes.
Wed May 22 19:38:27 2024 daemon.err odhcp6c[6053]: Failed to send RS (Network unreachable)
Wed May 22 19:38:27 2024 daemon.err odhcp6c[6053]: Failed to send RELEASE message to ff02::1:2 (Network unreachable)
Wed May 22 19:38:27 2024 daemon.notice netifd: Interface 'wan_6' is disabled
Wed May 22 19:38:27 2024 daemon.notice netifd: Network device 'pppoe-wan' link is down
Wed May 22 19:38:27 2024 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Wed May 22 19:38:27 2024 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Wed May 22 19:38:27 2024 daemon.notice netifd: Interface 'wan' has lost the connection
Wed May 22 19:38:27 2024 daemon.warn dnsmasq[1]: no servers found in /tmp/resolv.conf.d/resolv.conf.auto, will retry
Wed May 22 19:38:27 2024 daemon.notice netifd: wan_6 (6053): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan_6" } (Permission denied)
Wed May 22 19:38:27 2024 daemon.err odhcp6c[6053]: Failed to send SOLICIT message to ff02::1:2 (Network unreachable)
Wed May 22 19:38:27 2024 daemon.notice netifd: Interface 'wan_6' is now down
Wed May 22 19:38:27 2024 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Wed May 22 19:38:27 2024 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Wed May 22 19:38:27 2024 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 2 names
Wed May 22 19:38:27 2024 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Wed May 22 19:38:28 2024 daemon.warn odhcpd[1762]: No default route present, overriding ra_lifetime!
Wed May 22 19:38:33 2024 daemon.notice pppd[5890]: Connection terminated.
Wed May 22 19:38:33 2024 daemon.info pppd[5890]: Connect time 14.2 minutes.
Wed May 22 19:38:33 2024 daemon.info pppd[5890]: Sent 6087000 bytes, received 98463578 bytes.
Wed May 22 19:38:33 2024 daemon.notice pppd[5890]: Modem hangup
Wed May 22 19:38:33 2024 daemon.info pppd[5890]: Exit.
Wed May 22 19:38:33 2024 daemon.notice netifd: Interface 'wan' is now down
Wed May 22 19:38:33 2024 daemon.notice netifd: Interface 'wan' is setting up now
Wed May 22 19:38:33 2024 daemon.info pppd[7481]: Plugin pppoe.so loaded.
Wed May 22 19:38:33 2024 daemon.info pppd[7481]: PPPoE plugin from pppd 2.4.9
Wed May 22 19:38:33 2024 daemon.notice pppd[7481]: pppd 2.4.9 started by root, uid 0
Wed May 22 19:38:33 2024 daemon.info pppd[7481]: PPP session is 27022
Wed May 22 19:38:33 2024 daemon.warn pppd[7481]: Connected to 60:7e:cd:95:90:5b via interface eth2.6
Wed May 22 19:38:33 2024 kern.info kernel: [ 8636.520904] pppoe-wan: renamed from ppp0
Wed May 22 19:38:33 2024 daemon.info pppd[7481]: Renamed interface ppp0 to pppoe-wan
Wed May 22 19:38:33 2024 daemon.info pppd[7481]: Using interface pppoe-wan
Wed May 22 19:38:33 2024 daemon.notice pppd[7481]: Connect: pppoe-wan <--> eth2.6
Wed May 22 19:38:36 2024 daemon.info pppd[7481]: Remote message: Authentication success,Welcome!
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: PAP authentication succeeded
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: peer from calling number 60:7E:CD:95:90:5B authorized
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: local  LL address fe80::50b5:efaf:42a4:d3c5
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: remote LL address fe80::627e:cdff:fe95:905b
Wed May 22 19:38:36 2024 daemon.notice netifd: Network device 'pppoe-wan' link is up
Wed May 22 19:38:36 2024 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Wed May 22 19:38:36 2024 daemon.notice netifd: Interface 'wan' is now up
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using nameserver 8.8.8.8#53
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using nameserver 8.8.4.4#53
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Wed May 22 19:38:36 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: local  IP address 86.87.38.190
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: remote IP address 195.190.228.4
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: primary   DNS address 195.121.1.34
Wed May 22 19:38:36 2024 daemon.notice pppd[7481]: secondary DNS address 195.121.1.66
Wed May 22 19:38:36 2024 daemon.notice netifd: Interface 'wan_6' is enabled
Wed May 22 19:38:36 2024 daemon.notice netifd: Interface 'wan_6' has link connectivity
Wed May 22 19:38:36 2024 daemon.notice netifd: Interface 'wan_6' is setting up now
Wed May 22 19:38:36 2024 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Wed May 22 19:38:37 2024 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Wed May 22 19:38:45 2024 daemon.warn dnsmasq[1]: possible DNS-rebind attack detected: dns.msftncsi.com
Wed May 22 19:38:51 2024 daemon.notice netifd: Interface 'wan_6' is now up
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using nameserver 8.8.8.8#53
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using nameserver 8.8.4.4#53
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Wed May 22 19:38:51 2024 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 4 names
Wed May 22 19:38:51 2024 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Wed May 22 19:38:51 2024 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)

I have tried switching the eth interface just in case the NIC was faulty but didn't help. Downgrading back to 22.03 works but that one has other problems with mt7915e Wi-Fi so I'd rather stay with 23.05 if I can solve this problem.

My network config:


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

config globals 'globals'
	option ula_prefix 'fd1e:7a1d:3080::/48'

config device
	option name 'br-lan'
	option type 'bridge'
	list ports 'eth0'
	list ports 'eth1'
	list ports 'eth2'

config interface 'lan'
	option device 'br-lan'
	option proto 'static'
	option ipaddr '192.168.1.1'
	option netmask '255.255.255.0'
	option ip6assign '60'

config interface 'wan'
	option proto 'pppoe'
	option username 'internet'
	option password 'internet'
	option mtu '1500'
	option peerdns '0'
	list dns '8.8.8.8'
	list dns '8.8.4.4'
	option device 'eth2.6'
	option metric '1'
	option force_link '1'
	option keepalive '5 5'
	option ipv6 'auto'

config device
	option name 'eth2'
	option mtu6 '1512'
	option mtu '1512'

config device
	option type '8021q'
	option ifname 'eth2'
	option vid '6'
	option name 'eth2.6'
	option mtu '1508'

I've also tired without

option force_link '1'
option keepalive '5 5'

but didn't help either. I'm on x86_64 with i226 NICs. Any help would be appreciated.

should be 1492 inside and 1500 outside 9or plainly do not set any mtu

1 Like

https://openwrt.org/docs/guide-user/network/wan/isp-configurations#kpn_ftth
According to this, the config should be correct. I have also VLAN so that's extra 4 bytes hence 1512 at the top. Like I said, 22.03 worked for at least a year without any problems and with the exact same config so I'm positive it's not a MTU issue.

Lets start with adding debug option to pppd https://openwrt.org/docs/guide-user/network/wan/wan_interface_protocols

1 Like

The link stayed up for more than 24 hours and finally had another downtime.
Below is the log with ppp debug enabled.
I've noticed the problem might not actually be the ppp but that the NIC keeps going down. I have 4 ports on my router so I tried the other ones too and same thing happens. Any idea how I can debug that? Where can I see the reason for the NIC going down?

Fri May 24 11:06:35 2024 kern.info kernel: [53083.661573] igc 0000:03:00.0 eth2: NIC Link is Down
Fri May 24 11:06:35 2024 kern.info kernel: [53083.667436] br-lan: port 3(eth2) entered disabled state
Fri May 24 11:06:35 2024 daemon.notice netifd: Network device 'eth2' link is down
Fri May 24 11:06:35 2024 daemon.notice netifd: 8021q 'eth2.6' link is down
Fri May 24 11:06:35 2024 daemon.notice netifd: Interface 'wan' has link connectivity loss
Fri May 24 11:06:40 2024 kern.info kernel: [53087.951802] igc 0000:03:00.0 eth2: NIC Link is Up 2500 Mbps Full Duplex, Flow Control: RX
Fri May 24 11:06:40 2024 kern.info kernel: [53087.960640] br-lan: port 3(eth2) entered blocking state
Fri May 24 11:06:40 2024 kern.info kernel: [53087.966204] br-lan: port 3(eth2) entered forwarding state
Fri May 24 11:06:40 2024 daemon.notice netifd: Network device 'eth2' link is up
Fri May 24 11:06:40 2024 daemon.notice netifd: 8021q 'eth2.6' link is up
Fri May 24 11:06:40 2024 daemon.notice netifd: Interface 'wan' has link connectivity
Fri May 24 11:09:39 2024 kern.info kernel: [53267.430573] igc 0000:03:00.0 eth2: NIC Link is Down
Fri May 24 11:09:39 2024 kern.info kernel: [53267.436563] br-lan: port 3(eth2) entered disabled state
Fri May 24 11:09:39 2024 daemon.notice netifd: Network device 'eth2' link is down
Fri May 24 11:09:39 2024 daemon.notice netifd: 8021q 'eth2.6' link is down
Fri May 24 11:09:39 2024 daemon.notice netifd: Interface 'wan' has link connectivity loss
Fri May 24 11:09:44 2024 kern.info kernel: [53271.780804] igc 0000:03:00.0 eth2: NIC Link is Up 2500 Mbps Full Duplex, Flow Control: RX
Fri May 24 11:09:44 2024 kern.info kernel: [53271.789577] br-lan: port 3(eth2) entered blocking state
Fri May 24 11:09:44 2024 kern.info kernel: [53271.795169] br-lan: port 3(eth2) entered forwarding state
Fri May 24 11:09:44 2024 daemon.notice netifd: Network device 'eth2' link is up
Fri May 24 11:09:44 2024 daemon.notice netifd: 8021q 'eth2.6' link is up
Fri May 24 11:09:44 2024 daemon.notice netifd: Interface 'wan' has link connectivity
Fri May 24 11:09:44 2024 kern.info kernel: [53272.030548] igc 0000:03:00.0 eth2: NIC Link is Down
Fri May 24 11:09:45 2024 daemon.notice netifd: Network device 'eth2' link is down
Fri May 24 11:09:45 2024 daemon.notice netifd: 8021q 'eth2.6' link is down
Fri May 24 11:09:45 2024 daemon.notice netifd: Interface 'wan' has link connectivity loss
Fri May 24 11:09:45 2024 kern.info kernel: [53272.791137] br-lan: port 3(eth2) entered disabled state
Fri May 24 11:09:48 2024 kern.info kernel: [53276.220775] igc 0000:03:00.0 eth2: NIC Link is Up 2500 Mbps Full Duplex, Flow Control: RX
Fri May 24 11:09:48 2024 kern.info kernel: [53276.229704] br-lan: port 3(eth2) entered blocking state
Fri May 24 11:09:48 2024 kern.info kernel: [53276.235406] br-lan: port 3(eth2) entered forwarding state
Fri May 24 11:09:48 2024 daemon.notice netifd: Network device 'eth2' link is up
Fri May 24 11:09:48 2024 daemon.notice netifd: 8021q 'eth2.6' link is up
Fri May 24 11:09:48 2024 daemon.notice netifd: Interface 'wan' has link connectivity
Fri May 24 11:10:11 2024 daemon.info pppd[4172]: No response to 5 echo-requests
Fri May 24 11:10:11 2024 daemon.notice pppd[4172]: Serial link appears to be disconnected.
Fri May 24 11:10:11 2024 daemon.info pppd[4172]: Connect time 887.9 minutes.
Fri May 24 11:10:11 2024 daemon.info pppd[4172]: Sent 1065793700 bytes, received 4182955944 bytes.
Fri May 24 11:10:11 2024 daemon.debug pppd[4172]: Script /lib/netifd/ppp-down started (pid 6055)
Fri May 24 11:10:11 2024 daemon.err odhcp6c[4257]: Failed to send RS (Network unreachable)
Fri May 24 11:10:11 2024 daemon.err odhcp6c[4257]: Failed to send RELEASE message to ff02::1:2 (Network unreachable)
Fri May 24 11:10:11 2024 daemon.notice netifd: Interface 'wan_6' is disabled
Fri May 24 11:10:11 2024 daemon.notice netifd: Network device 'pppoe-wan' link is down
Fri May 24 11:10:11 2024 daemon.notice netifd: Network alias 'pppoe-wan' link is down
Fri May 24 11:10:11 2024 daemon.notice netifd: Interface 'wan_6' has link connectivity loss
Fri May 24 11:10:11 2024 daemon.debug pppd[4172]: Script /lib/netifd/ppp-down started (pid 6057)
Fri May 24 11:10:11 2024 daemon.debug pppd[4172]: sent [LCP TermReq id=0x2 "Peer not responding"]
Fri May 24 11:10:11 2024 daemon.notice netifd: Interface 'wan' has lost the connection
Fri May 24 11:10:11 2024 daemon.warn dnsmasq[1]: no servers found in /tmp/resolv.conf.d/resolv.conf.auto, will retry
Fri May 24 11:10:11 2024 daemon.debug pppd[4172]: Script /lib/netifd/ppp-down finished (pid 6055), status = 0x1
Fri May 24 11:10:11 2024 daemon.debug pppd[4172]: Script /lib/netifd/ppp-down finished (pid 6057), status = 0x1
Fri May 24 11:10:11 2024 daemon.notice netifd: wan_6 (4257): Command failed: ubus call network.interface notify_proto { "action": 0, "link-up": false, "keep": false, "interface": "wan_6" } (Permission denied)
Fri May 24 11:10:11 2024 daemon.err odhcp6c[4257]: Failed to send SOLICIT message to ff02::1:2 (Network unreachable)
Fri May 24 11:10:11 2024 daemon.notice netifd: Interface 'wan_6' is now down
Fri May 24 11:10:11 2024 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Fri May 24 11:10:11 2024 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Fri May 24 11:10:11 2024 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 4 names
Fri May 24 11:10:11 2024 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Fri May 24 11:10:12 2024 daemon.warn odhcpd[1787]: No default route present, overriding ra_lifetime!
Fri May 24 11:10:12 2024 daemon.warn odhcpd[1787]: No default route present, overriding ra_lifetime!
Fri May 24 11:10:14 2024 daemon.debug pppd[4172]: sent [LCP TermReq id=0x3 "Peer not responding"]
Fri May 24 11:10:17 2024 daemon.notice pppd[4172]: Connection terminated.
Fri May 24 11:10:17 2024 daemon.info pppd[4172]: Connect time 887.9 minutes.
Fri May 24 11:10:17 2024 daemon.info pppd[4172]: Sent 1065793700 bytes, received 4182955944 bytes.
Fri May 24 11:10:17 2024 daemon.notice pppd[4172]: Modem hangup
Fri May 24 11:10:17 2024 daemon.info pppd[4172]: Exit.
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan' is now down
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan' is setting up now
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: Plugin pppoe.so loaded.
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: PPPoE plugin from pppd 2.4.9
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: pppd 2.4.9 started by root, uid 0
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Send PPPOE Discovery V1T1 PADI session 0x0 length 18
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  dst ff:ff:ff:ff:ff:ff  src 60:be:b4:06:dc:f3
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  [service-name] [host-uniq  3d 18 00 00] [PPP-max-payload  05 dc]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 39
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  dst 60:be:b4:06:dc:f3  src 60:7e:cd:95:90:5b
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  [service-name] [host-uniq  3d 18 00 00] [PPP-max-payload  05 dc] [AC-name 195.190.228.4] [end-of-list]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Send PPPOE Discovery V1T1 PADR session 0x0 length 18
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  dst 60:7e:cd:95:90:5b  src 60:be:b4:06:dc:f3
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  [service-name] [host-uniq  3d 18 00 00] [PPP-max-payload  05 dc]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Recv PPPOE Discovery V1T1 PADS session 0x900a length 22
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  dst 60:be:b4:06:dc:f3  src 60:7e:cd:95:90:5b
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]:  [service-name] [host-uniq  3d 18 00 00] [PPP-max-payload  05 dc] [end-of-list]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: PADS: Service-Name: ''
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: PPP session is 36874
Fri May 24 11:10:17 2024 daemon.warn pppd[6205]: Connected to 60:7e:cd:95:90:5b via interface eth2.6
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: using channel 2
Fri May 24 11:10:17 2024 kern.info kernel: [53305.131013] pppoe-wan: renamed from ppp0
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: Renamed interface ppp0 to pppoe-wan
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: Using interface pppoe-wan
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: Connect: pppoe-wan <--> eth2.6
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [LCP ConfReq id=0x1 <magic 0xab338a89>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [LCP ConfReq id=0x2 <mru 1500> <auth pap> <magic 0xc56b000e>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [LCP ConfAck id=0x2 <mru 1500> <auth pap> <magic 0xc56b000e>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [LCP ConfAck id=0x1 <magic 0xab338a89>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [LCP EchoReq id=0x0 magic=0xab338a89]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [PAP AuthReq id=0x1 user="internet" password=<hidden>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [LCP EchoRep id=0x0 magic=0xc56b000e]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [PAP AuthAck id=0x1 "Authentication success,Welcome!"]
Fri May 24 11:10:17 2024 daemon.info pppd[6205]: Remote message: Authentication success,Welcome!
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: PAP authentication succeeded
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: peer from calling number 60:7E:CD:95:90:5B authorized
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [IPV6CP ConfReq id=0x1 <addr fe80::7c7e:98fc:2407:25ed>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::627e:cdff:fe95:905b>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [IPV6CP ConfAck id=0x1 <addr fe80::627e:cdff:fe95:905b>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [IPCP ConfReq id=0x1 <addr 195.190.228.4>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [IPCP ConfAck id=0x1 <addr 195.190.228.4>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::7c7e:98fc:2407:25ed>]
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: local  LL address fe80::7c7e:98fc:2407:25ed
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: remote LL address fe80::627e:cdff:fe95:905b
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Script /lib/netifd/ppp6-up started (pid 6226)
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [IPCP ConfNak id=0x1 <addr 86.87.38.190> <ms-dns1 195.121.1.34> <ms-dns2 195.121.1.66>]
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: sent [IPCP ConfReq id=0x2 <addr 86.87.38.190> <ms-dns1 195.121.1.34> <ms-dns2 195.121.1.66>]
Fri May 24 11:10:17 2024 daemon.notice netifd: Network device 'pppoe-wan' link is up
Fri May 24 11:10:17 2024 daemon.notice netifd: Network alias 'pppoe-wan' link is up
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan' is now up
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using nameserver 8.8.8.8#53
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using nameserver 8.8.4.4#53
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri May 24 11:10:17 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: rcvd [IPCP ConfAck id=0x2 <addr 86.87.38.190> <ms-dns1 195.121.1.34> <ms-dns2 195.121.1.66>]
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: local  IP address 86.87.38.190
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: remote IP address 195.190.228.4
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: primary   DNS address 195.121.1.34
Fri May 24 11:10:17 2024 daemon.notice pppd[6205]: secondary DNS address 195.121.1.66
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Script /lib/netifd/ppp-up started (pid 6253)
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan_6' is enabled
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan_6' has link connectivity
Fri May 24 11:10:17 2024 daemon.notice netifd: Interface 'wan_6' is setting up now
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Script /lib/netifd/ppp-up finished (pid 6253), status = 0x1
Fri May 24 11:10:17 2024 daemon.debug pppd[6205]: Script /lib/netifd/ppp6-up finished (pid 6226), status = 0x0
Fri May 24 11:10:17 2024 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Fri May 24 11:10:17 2024 user.notice firewall: Reloading firewall due to ifupdate of wan (pppoe-wan)
Fri May 24 11:10:31 2024 daemon.notice netifd: Interface 'wan_6' is now up
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using nameserver 8.8.8.8#53
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using nameserver 8.8.4.4#53
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 4 names
Fri May 24 11:10:31 2024 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 8 names
Fri May 24 11:10:31 2024 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Fri May 24 11:10:31 2024 user.notice firewall: Reloading firewall due to ifup of wan_6 (pppoe-wan)

hi,

  1. you seem to have a 2,5Gbps physical port, eth2. what is on the other end? speed/duplexity is manual or auto and in sync both ends? have you checked cabling and other end?
  2. mtu - can try with default settings or with the one your ISP recommend? as @brada4 said 1492 is the usal ppp(oe? i guess you have that) mtu but ISP may use different.
  3. do you use eth2 for other traffic, other than wan on eth2.6? why you add eth2 to br-lan? if that port is only used for wan you can remove it from br-lan imo.
  4. i have similar problems for quite a long time, i tried lots of things on my end but eventually it turned out that ISP side was not ok. they replaced the modem. so that is also a possibility you may consider.

The other side is the fiber optic box of my ISP. I'm pretty sure it's 1Gbps. Wouldn't my NIC auto-negotiate that and work in 1G mode? I would assume no connection at all if they mismatched?

I'm confident that my ISP default is 1500. I've been talking about it with them and many others in their public forum

Good point, I will remove it from LAN. I think it was just default like that when I first made the config and I never really paid attention to it. It's not used for anything else other than PPPoE connection to my ISP

Yes, that will be my next option. But in order to that I will have to do all tests with their own router box first. Otherwise I couldn't get them to look into it officially.

Thanks

1 Like

Good observation....
lets dig through autoneg data.

ethtool eth2
root@OpenWrt:~# ethtool eth2
Settings for eth2:
	Supported ports: [ TP ]
	Supported link modes:   10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	                        2500baseT/Full
	Supported pause frame use: Symmetric
	Supports auto-negotiation: Yes
	Supported FEC modes: Not reported
	Advertised link modes:  10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	                        2500baseT/Full
	Advertised pause frame use: Symmetric
	Advertised auto-negotiation: Yes
	Advertised FEC modes: Not reported
	Speed: 2500Mb/s
	Duplex: Full
	Auto-negotiation: on
	Port: Twisted Pair
	PHYAD: 0
	Transceiver: internal
	MDI-X: off (auto)
	Supports Wake-on: pumbg
	Wake-on: g
        Current message level: 0x00000007 (7)
                               drv probe link
	Link detected: yes

looks like the link speed is 2.5G. I will confirm if that should be the case for this FTU with my ISP.

problem with mismatched speed settings is not when the initial negotiation fails and you have no link at all, but when energy saving kicks in for example and then things go side ways very quickly for an otherwise working link. And 2.5Gb nics eats more than 1Gb so green mode probably is set by default, and have experienced lots of problems with wrong code/hw which sticks to low power mode etc.

not saying this is definitely your root cause but give a try to set manual speed/duplexity and disable green mode.

ok but how can it be in 2.5G mode if other can only do 1G??

Not sure really. I assumed the FTU would be 1G but maybe it's 2.5G. I'm confirming it with my ISP now.

If it's indeed 1G, would there be any reason for the negotiation to end up at 2.5G? Is this even possible?

that's what your nic reports. maybe it is a buggy driver ...

Try to not advertise 2.5Gbps (does not mean 2.5Gbps should be flopping like you see)

ethtool -s eth2 advertise 0x029
ethtool -r eth2

default was 0x80000000002f (see ethtool manual on full linux for details)

Wait for a while .... Command can be saved in /etc/rc.local before ehit0 line
You can confirm with ethtool eth2 that mode bits were set as dictated and 1Gbps full duplex is negotiated.

Is this what my NIC reports about the other end of the cable or is it what it advertises for itself? My understanding is the latter. Nonetheless the auto negotiation ended up at 2.5G and maybe I'm overthinking it. There is a high chance that the other end supports 2.5G unlike my initial assumption.

I'll force it to 1G just in case to see if it helps like @brada4 suggested

Just got a response from ISP

The LAN port of that ONT is a 10Gbps port.
I think forcing the port to 1Gbps might solve your problem.
1 Like
root@OpenWrt:~# ethtool -s eth2 advertise 0x02f
root@OpenWrt:~# ethtool -r eth2
root@OpenWrt:~# ethtool eth2
Settings for eth2:
	Supported ports: [ TP ]
	Supported link modes:   10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	                        2500baseT/Full
	Supported pause frame use: Symmetric
	Supports auto-negotiation: Yes
	Supported FEC modes: Not reported
	Advertised link modes:  10baseT/Half 10baseT/Full
	                        100baseT/Half 100baseT/Full
	                        1000baseT/Full
	Advertised pause frame use: Symmetric
	Advertised auto-negotiation: Yes
	Advertised FEC modes: Not reported
	Speed: 1000Mb/s
	Duplex: Full
	Auto-negotiation: on
	Port: Twisted Pair
	PHYAD: 0
	Transceiver: internal
	MDI-X: off (auto)
	Supports Wake-on: pumbg
	Wake-on: g
        Current message level: 0x00000007 (7)
                               drv probe link
	Link detected: yes

let's see how it works, will report back

In the meantime check cable, while 5E cable is rated to 2.5Gbps they are mostly used for 1Gbps and some loose ends may pass. Something shipped with router or ONT CPE is likely to be on a good side.

That was a fast fail. NIC just dropped again causing PPP to reset.
The cable is CAT6 and max 3m long.

I'll put it back to 2.5G and try 22.03 for prolonged time to try to reproduce the same problem. If I can't than I'll know it's a software issue. Otherwise time to call ISP I guess.

Any other things that I can try? Does igc driver give more detailed error messages somewhere?

Try adding option force_link '1' to the wan section in /etc/config/network that might help (as long as the outages are below the PPPoE timeout period)...