I am using BSNL as ISP in India, and they use PPPoE. I have tried on Linux (Endeavor OS), it works flawlessly as well as it used to work on pfSense.
Now the problem is It does not reconnect for a while, 1 – 5hr. And my ISP disconnects the connection every 24hrs from when it is connected. Even if I rebooted the OpenWrt, it takes a lot of time to get connected.
Maybe OpenWrt is not terminating the connection properly.
Please help me to fix this issue.
I am giving the configs and logs. If you need anything else please let me know.
cat /etc/config/network
config device
option name 'eth0.2'
option macaddr '3c:84:OPENWRTMAC'
config interface 'wan'
option keepalive '10 1'
option device 'eth0.200'
option proto 'pppoe'
option username 'X'
option password 'X'
option ipv6 '0'
option delegate '0'
cat /etc/ppp/options
debug
logfile /tmp/ppp.log
noipdefault
noaccomp
nopcomp
nocrtscts
lock
maxfail 0
#This lines are copied from linux for experimenting
#fromLINUX
asyncmap 0
proxyarp
lcp-echo-interval 30
lcp-echo-failure 4
lcp-restart 3
lcp-max-terminate 3
lcp-max-configure 10
lcp-max-failure 10
ipcp-restart 3
ipcp-max-terminate 3
ipcp-max-configure 3
ipcp-max-failure 10
pap-restart 3
pap-max-authreq 10
chap-restart 3
chap-max-challenge 10
This file is copied from linux for experimenting
cat /etc/ppp/options.l2tpd
login
lcp-echo-interval 10
lcp-echo-failure 2
noipx
refuse-pap
refuse-chap
refuse-mschap
require-mppe
require-mschap-v2
nodefaultroute
proxyarp
In openwrt
Wed Aug 23 17:14:17 2023 daemon.err insmod: module is already loaded - ppp_generic
Wed Aug 23 17:14:17 2023 daemon.err insmod: module is already loaded - pppox
Wed Aug 23 17:14:17 2023 daemon.err insmod: module is already loaded - pppoe
Wed Aug 23 17:14:17 2023 daemon.info pppd[13468]: Plugin pppoe.so loaded.
Wed Aug 23 17:14:17 2023 daemon.info pppd[13468]: PPPoE plugin from pppd 2.4.9
Wed Aug 23 17:14:17 2023 daemon.notice pppd[13468]: pppd 2.4.9 started by root, uid 0
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: Recv PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:17 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: Recv PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:22 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: Recv PPPOE Discovery V1T1 PADI session 0x0 length 12
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: dst ff:ff:ff:ff:ff:ff src OpenWRTMAC
Wed Aug 23 17:14:27 2023 daemon.debug pppd[13468]: [service-name] [host-uniq 00 00 34 9c]
Wed Aug 23 17:14:32 2023 daemon.warn pppd[13468]: Timeout waiting for PADO packets
Wed Aug 23 17:14:32 2023 daemon.err pppd[13468]: Unable to complete PPPoE Discovery
Wed Aug 23 17:14:32 2023 daemon.info pppd[13468]: Exit.
IN Linux (Disconnected and connected instantly)
Aug 23 18:50:43 desktop NetworkManager[475]: <info> [1692796843.4707] audit: op="device-disconnect" interface="ppp0" ifindex=7 pid=1112 uid=1000 result="success"
Aug 23 18:50:43 desktop pppd[33819]: Terminating on signal 15
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: status 10 / phase 'terminate'
Aug 23 18:50:43 desktop pppd[33819]: Connect time 8.7 minutes.
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: status 8 / phase 'network'
Aug 23 18:50:43 desktop pppd[33819]: Sent 585415 bytes, received 4894644 bytes.
Aug 23 18:50:43 desktop pppd[33819]: Script /etc/ppp/ip-down started (pid 36489)
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: status 5 / phase 'establish'
Aug 23 18:50:43 desktop NetworkManager[33819]: Script /etc/ppp/ip-down started (pid 36489)
Aug 23 18:50:43 desktop dbus-daemon[444]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.8" (uid=0 pid=475 comm="/usr/bin/NetworkManager --no-daemon") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.9055" (uid=0 pid=33819 comm="/usr/bin/pppd nodetach lock nodefaultroute ipv6 ,")
Aug 23 18:50:43 desktop dbus-daemon[444]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.8" (uid=0 pid=475 comm="/usr/bin/NetworkManager --no-daemon") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.9055" (uid=0 pid=33819 comm="/usr/bin/pppd nodetach lock nodefaultroute ipv6 ,")
Aug 23 18:50:43 desktop pppd[33819]: sent [LCP TermReq id=0x3 "User request"]
Aug 23 18:50:43 desktop dbus-daemon[444]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.8" (uid=0 pid=475 comm="/usr/bin/NetworkManager --no-daemon") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.9055" (uid=0 pid=33819 comm="/usr/bin/pppd nodetach lock nodefaultroute ipv6 ,")
Aug 23 18:50:43 desktop pppd[33819]: rcvd [LCP TermAck id=0x3]
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: status 11 / phase 'disconnect'
Aug 23 18:50:43 desktop pppd[33819]: Connection terminated.
Aug 23 18:50:43 desktop dbus-daemon[444]: [system] Rejected send message, 0 matched rules; type="error", sender=":1.8" (uid=0 pid=475 comm="/usr/bin/NetworkManager --no-daemon") interface="(unset)" member="(unset)" error name="org.freedesktop.DBus.Error.UnknownMethod" requested_reply="0" destination=":1.9055" (uid=0 pid=33819 comm="/usr/bin/pppd nodetach lock nodefaultroute ipv6 ,")
Aug 23 18:50:43 desktop NetworkManager[475]: <info> [1692796843.5471] device (ppp0): state change: disconnected -> unmanaged (reason 'unmanaged', sys-iface-state: 'removed')
Aug 23 18:50:43 desktop pppd[33819]: Waiting for 1 child processes...
Aug 23 18:50:43 desktop NetworkManager[33819]: script /etc/ppp/ip-down, pid 36489
Aug 23 18:50:43 desktop pppd[33819]: script /etc/ppp/ip-down, pid 36489
Aug 23 18:50:43 desktop pppd[33819]: Script /etc/ppp/ip-down finished (pid 36489), status = 0x0
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: status 1 / phase 'dead'
Aug 23 18:50:43 desktop NetworkManager[33819]: Script /etc/ppp/ip-down finished (pid 36489), status = 0x0
Aug 23 18:50:43 desktop pppd[33819]: Exit.
Aug 23 18:50:43 desktop pppd[33819]: nm-ppp-plugin: cleaning up
Aug 23 18:50:45 desktop NetworkManager[475]: <info> [1692796845.6682] device (enp2s0): Activation: starting connection 'New pppoe connection' (7c15421d-136d-4d16-b501-222498aca7d7)
Aug 23 18:50:45 desktop NetworkManager[475]: <info> [1692796845.6683] audit: op="connection-activate" uuid="7c15421d-136d-4d16-b501-222498aca7d7" name="New pppoe connection" pid=1112 uid=1000 result="success"
Aug 23 18:50:47 desktop NetworkManager[475]: <info> [1692796847.8213] ppp-manager: starting PPP connection
Aug 23 18:50:47 desktop NetworkManager[475]: <info> [1692796847.8257] ppp-manager: pppd started with pid 36602
Aug 23 18:50:47 desktop pppd[36602]: Plugin rp-pppoe.so loaded.
Aug 23 18:50:47 desktop NetworkManager[36602]: Plugin rp-pppoe.so loaded.
Aug 23 18:50:47 desktop NetworkManager[36602]: PPPoE plugin from pppd 2.4.9
Aug 23 18:50:47 desktop pppd[36602]: PPPoE plugin from pppd 2.4.9
Aug 23 18:50:47 desktop pppd[36602]: Plugin /usr/lib/pppd/2.4.9/nm-pppd-plugin.so loaded.
Aug 23 18:50:47 desktop NetworkManager[36602]: Plugin /usr/lib/pppd/2.4.9/nm-pppd-plugin.so loaded.
Aug 23 18:50:47 desktop pppd[36602]: nm-ppp-plugin: initializing
Aug 23 18:50:47 desktop pppd[36602]: pppd 2.4.9 started by root, uid 0
Aug 23 18:50:47 desktop pppd[36602]: nm-ppp-plugin: status 3 / phase 'serial connection'
Aug 23 18:50:47 desktop pppd[36602]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Aug 23 18:50:47 desktop pppd[36602]: dst ff:ff:ff:ff:ff:ff src OpenWRTMACClone
Aug 23 18:50:47 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00]
Aug 23 18:50:47 desktop pppd[36602]: Recv PPPOE Discovery V1T1 PADI session 0x0 length 12
Aug 23 18:50:47 desktop pppd[36602]: dst ff:ff:ff:ff:ff:ff src OpenWRTMACClone
Aug 23 18:50:47 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00]
Aug 23 18:50:52 desktop pppd[36602]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Aug 23 18:50:52 desktop pppd[36602]: dst ff:ff:ff:ff:ff:ff src OpenWRTMACClone
Aug 23 18:50:52 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00]
Aug 23 18:50:52 desktop pppd[36602]: Recv PPPOE Discovery V1T1 PADI session 0x0 length 12
Aug 23 18:50:52 desktop pppd[36602]: dst ff:ff:ff:ff:ff:ff src OpenWRTMACClone
Aug 23 18:50:52 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00]
Aug 23 18:50:52 desktop pppd[36602]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 228
Aug 23 18:50:52 desktop pppd[36602]: dst OpenWRTMACClone src ISPMAC
Aug 23 18:50:52 desktop pppd[36602]: [host-uniq fa 8e 00 00] [AC-name SOMEAC-NAME] [service-name SOME_SERVICE_NAME1] [service-name SOME_SERVICE_NAME2] [service-name SOME_SERVICE_NAME3] [service-name SOME_SERVICE_NAME4] [service-name SOME_SERVICE_NAME5] [service-name SOME_SERVICE_NAME6] [service-name
Aug 23 18:50:52 desktop pppd[36602]: SOME_SERVICE_NAME6] [service-name SOME_SERVICE_NAME7] [service-name SOME_SERVICE_NAME8] [service-name SOME_SERVICE_NAME9] [service-name SOME_SERVICE_NAME10]
Aug 23 18:50:52 desktop pppd[36602]: Send PPPOE Discovery V1T1 PADR session 0x0 length 12
Aug 23 18:50:52 desktop pppd[36602]: dst ISPMAC src OpenWRTMACClone
Aug 23 18:50:52 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00]
Aug 23 18:50:53 desktop pppd[36602]: Recv PPPOE Discovery V1T1 PADS session 0x4a9 length 49
Aug 23 18:50:53 desktop pppd[36602]: dst OpenWRTMACClone src ISPMAC
Aug 23 18:50:53 desktop pppd[36602]: [service-name] [host-uniq fa 8e 00 00] [AC-name SOMEAC-NAME]
Aug 23 18:50:53 desktop pppd[36602]: PADS: Service-Name: ''
Aug 23 18:50:53 desktop pppd[36602]: PPP session is 1193
Aug 23 18:50:53 desktop pppd[36602]: Connected to ISPMAC via interface enp2s0
Aug 23 18:50:53 desktop pppd[36602]: using channel 4
Aug 23 18:50:53 desktop pppd[36602]: Using interface ppp0
Aug 23 18:50:53 desktop pppd[36602]: nm-ppp-plugin: status 5 / phase 'establish'
Aug 23 18:50:53 desktop NetworkManager[36602]: Using interface ppp0
Aug 23 18:50:53 desktop NetworkManager[36602]: Connect: ppp0 <--> enp2s0
Aug 23 18:50:53 desktop pppd[36602]: Connect: ppp0 <--> enp2s0
Aug 23 18:50:53 desktop pppd[36602]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xc4822e9d>]
Aug 23 18:50:53 desktop NetworkManager[475]: <info> [1692796853.6272] manager: (ppp0): new Ppp device (/org/freedesktop/NetworkManager/Devices/9)
Aug 23 18:50:53 desktop pppd[36602]: rcvd [LCP ConfReq id=0xd8 <mru 1460> <auth chap MD5> <magic 0x3c43b9fc>]
Aug 23 18:50:53 desktop pppd[36602]: sent [LCP ConfAck id=0xd8 <mru 1460> <auth chap MD5> <magic 0x3c43b9fc>]
Aug 23 18:50:53 desktop pppd[36602]: rcvd [LCP ConfNak id=0x1 <mru 1460>]
Aug 23 18:50:53 desktop pppd[36602]: sent [LCP ConfReq id=0x2 <mru 1460> <magic 0xc4822e9d>]
Aug 23 18:50:53 desktop pppd[36602]: rcvd [LCP ConfAck id=0x2 <mru 1460> <magic 0xc4822e9d>]
Aug 23 18:50:53 desktop pppd[36602]: nm-ppp-plugin: status 6 / phase 'authenticate'
Aug 23 18:50:53 desktop pppd[36602]: rcvd [CHAP Challenge id=0x1 <d676499f9590f7c83e44a8a5a0838a94>, name = "SOMEAC-NAME"]
Aug 23 18:50:53 desktop pppd[36602]: nm-ppp-plugin: passwd-hook, requesting credentials...
Aug 23 18:50:53 desktop pppd[36602]: nm-ppp-plugin: got credentials from NetworkManager
Aug 23 18:50:53 desktop pppd[36602]: sent [CHAP Response id=0x1 <8d81bf6dffc42f12c24b5f8de96301b5>, name = "X"]
Aug 23 18:50:54 desktop pppd[36602]: rcvd [CHAP Success id=0x1 "Authentication Success"]
Aug 23 18:50:54 desktop pppd[36602]: nm-ppp-plugin: status 8 / phase 'network'
Aug 23 18:50:54 desktop pppd[36602]: CHAP authentication succeeded: Authentication Success
Aug 23 18:50:54 desktop pppd[36602]: CHAP authentication succeeded
Aug 23 18:50:54 desktop pppd[36602]: peer from calling number ISPMAC authorized
Aug 23 18:50:54 desktop pppd[36602]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Aug 23 18:50:54 desktop pppd[36602]: sent [IPV6CP ConfReq id=0x1 <addr fe80::0053:ee04:581b:4ff8>]
Aug 23 18:50:54 desktop pppd[36602]: rcvd [IPCP ConfReq id=0x6f <addr PUBLIC.IP.1>]
Aug 23 18:50:54 desktop pppd[36602]: sent [IPCP ConfAck id=0x6f <addr PUBLIC.IP.1>]
Aug 23 18:50:54 desktop pppd[36602]: rcvd [IPCP ConfNak id=0x1 <addr PUBLIC.IP.59> <ms-dns1 PUBLIC.IP.193> <ms-dns2 PUBLIC.IP.225>]
Aug 23 18:50:54 desktop pppd[36602]: sent [IPCP ConfReq id=0x2 <addr PUBLIC.IP.59> <ms-dns1 PUBLIC.IP.193> <ms-dns2 PUBLIC.IP.225>]
Aug 23 18:50:54 desktop pppd[36602]: rcvd [LCP ProtRej id=0xd9 80 57 01 01 00 0e 01 0a 00 53 ee 04 58 1b 4f f8]
Aug 23 18:50:54 desktop pppd[36602]: Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received
Aug 23 18:50:54 desktop pppd[36602]: rcvd [IPCP ConfAck id=0x2 <addr PUBLIC.IP.59> <ms-dns1 PUBLIC.IP193> <ms-dns2 PUBLIC.IP225>]
Aug 23 18:50:54 desktop pppd[36602]: Cannot determine ethernet address for proxy ARP
Aug 23 18:50:54 desktop pppd[36602]: nm-ppp-plugin: status 9 / phase 'running'
Aug 23 18:50:54 desktop pppd[36602]: local IP address PUBLIC.IP.59
Aug 23 18:50:54 desktop NetworkManager[475]: <info> [1692796854.2893] device (ppp0): state change: unmanaged -> unavailable (reason 'connection-assumed', sys-iface-state: 'external')
Aug 23 18:50:54 desktop pppd[36602]: remote IP address PUBLIC.IP.1
Aug 23 18:50:54 desktop pppd[36602]: primary DNS address PUBLIC.IP193
Aug 23 18:50:54 desktop pppd[36602]: secondary DNS address PUBLIC.IP225
Aug 23 18:50:54 desktop NetworkManager[475]: <info> [1692796854.2905] device (ppp0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'external')
Aug 23 18:50:54 desktop pppd[36602]: nm-ppp-plugin: ip-up event
Aug 23 18:50:54 desktop pppd[36602]: nm-ppp-plugin: sending IPv4 config to NetworkManager...
Aug 23 18:50:54 desktop pppd[36602]: Script /etc/ppp/ip-up started (pid 36642)
Aug 23 18:50:54 desktop NetworkManager[36602]: Script /etc/ppp/ip-up started (pid 36642)
Aug 23 18:50:54 desktop NetworkManager[475]: <info> [1692796854.2986] ppp-manager: (IPv4 Config Get) reply received.
Aug 23 18:50:54 desktop NetworkManager[475]: <info> [1692796854.3101] policy: set 'New pppoe connection' (ppp0) as default for IPv4 routing and DNS
Aug 23 18:50:54 desktop pppd[36602]: Script /etc/ppp/ip-up finished (pid 36642), status = 0x0
Aug 23 18:50:54 desktop NetworkManager[36602]: Script /etc/ppp/ip-up finished (pid 36642), status = 0x0
Aug 23 18:50:59 desktop NetworkManager[475]: <info> [1692796859.3369] audit: op="device-disconnect" interface="ppp0" ifindex=8 pid=1112 uid=1000 result="success"
Thank you for reading... 