PPPoE disconnects few times a day for 20 seconds
-
We have a router that disconnects PPPoE multiple times a day. The connection comes back after 20 seconds.
The modem is a Bell Hub 2000 (in Canada). I would like to know if anyone else has this issue ? The modem was replaced by Bell for another one (the same model) and the issue persists.
pfSense version is 2.4.5-RELEASE (amd64)
Here are the logs when the issue happens:
Mar 18 12:16:51 check_reload_status Linkup starting igb0 Mar 18 12:16:51 kernel igb0: link state changed to DOWN Mar 18 12:16:52 check_reload_status Reloading filter Mar 18 12:16:54 kernel igb0: link state changed to UP Mar 18 12:16:54 check_reload_status Linkup starting igb0 Mar 18 12:16:55 ppp Multi-link PPP daemon for FreeBSD Mar 18 12:16:55 ppp process 35503 started, version 5.8 (root@pfSense_v2_4_5_amd64-pfSense_v2_4_5-job-04 20:28 17-Dec-2019) Mar 18 12:16:55 ppp waiting for process 20577 to die... Mar 18 12:16:55 ppp caught fatal signal TERM Mar 18 12:16:55 ppp [wan] IFACE: Close event Mar 18 12:16:55 ppp [wan] IPCP: Close event Mar 18 12:16:55 ppp [wan] IPCP: state change Opened --> Closing Mar 18 12:16:55 ppp [wan] IPCP: SendTerminateReq #4 Mar 18 12:16:55 ppp [wan] IPCP: LayerDown Mar 18 12:16:55 php-fpm /rc.linkup: Default gateway setting Interface WAN_PPPOE Gateway as default. Mar 18 12:16:55 php-fpm /rc.linkup: Gateway, none 'available' for inet6, use the first one configured. '' Mar 18 12:16:55 check_reload_status Restarting ipsec tunnels Mar 18 12:16:55 check_reload_status Rewriting resolv.conf Mar 18 12:16:55 ppp [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address Mar 18 12:16:55 ppp [wan] IFACE: Down event Mar 18 12:16:55 ppp [wan] IFACE: Rename interface pppoe0 to pppoe0 Mar 18 12:16:55 ppp [wan] IPV6CP: Close event Mar 18 12:16:55 ppp [wan] IPV6CP: state change Stopped --> Closed Mar 18 12:16:55 ppp [wan] IPCP: rec'd Terminate Ack #4 (Closing) Mar 18 12:16:55 ppp [wan] IPCP: state change Closing --> Closed Mar 18 12:16:55 ppp [wan] IPCP: LayerFinish Mar 18 12:16:55 ppp [wan] Bundle: No NCPs left. Closing links... Mar 18 12:16:55 ppp [wan] Bundle: closing link "wan_link0"... Mar 18 12:16:55 ppp [wan_link0] Link: CLOSE event Mar 18 12:16:55 ppp [wan_link0] LCP: Close event Mar 18 12:16:55 ppp [wan_link0] LCP: state change Opened --> Closing Mar 18 12:16:55 ppp [wan_link0] Link: Leave bundle "wan" Mar 18 12:16:55 ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Mar 18 12:16:55 ppp [wan] IPCP: Close event Mar 18 12:16:55 ppp [wan] IPV6CP: Close event Mar 18 12:16:55 ppp [wan] IPCP: Down event Mar 18 12:16:55 ppp [wan] IPCP: state change Closed --> Initial Mar 18 12:16:55 ppp [wan] IPV6CP: Down event Mar 18 12:16:55 ppp [wan] IPV6CP: state change Closed --> Initial Mar 18 12:16:55 ppp [wan_link0] LCP: SendTerminateReq #5 Mar 18 12:16:55 ppp [wan_link0] LCP: LayerDown Mar 18 12:16:56 ppp [wan_link0] rec'd proto IP during terminate phase Mar 18 12:16:56 ppp [wan_link0] rec'd proto IP during terminate phase Mar 18 12:16:56 ppp [wan_link0] PPPoE: connection closed Mar 18 12:16:56 ppp [wan_link0] Link: DOWN event Mar 18 12:16:56 ppp [wan_link0] LCP: Down event Mar 18 12:16:56 ppp [wan_link0] LCP: LayerFinish Mar 18 12:16:56 ppp [wan_link0] LCP: state change Closing --> Initial Mar 18 12:16:56 ppp waiting for process 20577 to die... Mar 18 12:16:57 ppp waiting for process 20577 to die... Mar 18 12:16:57 ppp [wan] Bundle: Shutdown Mar 18 12:16:57 ppp [wan_link0] Link: Shutdown Mar 18 12:16:57 ppp process 20577 terminated Mar 18 12:16:58 ppp web: web is not running Mar 18 12:16:58 ppp [wan] Bundle: Interface ng0 created Mar 18 12:16:58 ppp [wan_link0] Link: OPEN event Mar 18 12:16:58 kernel ng0: changing name to 'pppoe0' Mar 18 12:16:58 ppp [wan_link0] LCP: Open event Mar 18 12:16:58 ppp [wan_link0] LCP: state change Initial --> Starting Mar 18 12:16:58 ppp [wan_link0] LCP: LayerStart Mar 18 12:16:58 ppp [wan_link0] PPPoE: Connecting to '' Mar 18 12:16:58 ppp PPPoE: rec'd ACNAME "VDRLPQXXXXXX" Mar 18 12:16:58 ppp [wan_link0] PPPoE: connection successful Mar 18 12:16:58 ppp [wan_link0] Link: UP event Mar 18 12:16:58 ppp [wan_link0] LCP: Up event Mar 18 12:16:58 ppp [wan_link0] LCP: state change Starting --> Req-Sent Mar 18 12:16:58 ppp [wan_link0] LCP: SendConfigReq #1 Mar 18 12:16:58 ppp [wan_link0] PROTOCOMP Mar 18 12:16:58 ppp [wan_link0] MRU 1492 Mar 18 12:16:58 ppp [wan_link0] MAGICNUM 0xf9XXXXXXXX Mar 18 12:16:58 ppp [wan_link0] LCP: rec'd Configure Reject #1 (Req-Sent) Mar 18 12:16:58 ppp [wan_link0] PROTOCOMP Mar 18 12:16:58 ppp [wan_link0] LCP: SendConfigReq #2 Mar 18 12:16:58 ppp [wan_link0] MRU 1492 Mar 18 12:16:58 ppp [wan_link0] MAGICNUM 0xf9XXXXXXX Mar 18 12:16:58 ppp [wan_link0] LCP: rec'd Configure Ack #2 (Req-Sent) Mar 18 12:16:58 ppp [wan_link0] MRU 1492 Mar 18 12:16:58 ppp [wan_link0] MAGICNUM 0xf9XXXXXXX Mar 18 12:16:58 ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd Mar 18 12:16:59 check_reload_status updating dyndns wan Mar 18 12:16:59 check_reload_status Reloading filter Mar 18 12:17:00 ppp [wan_link0] LCP: state change Ack-Rcvd --> Req-Sent Mar 18 12:17:00 ppp [wan_link0] LCP: SendConfigReq #3 Mar 18 12:17:00 ppp [wan_link0] MRU 1492 Mar 18 12:17:00 ppp [wan_link0] MAGICNUM 0xf9XXXXXXX Mar 18 12:17:00 ppp [wan_link0] LCP: rec'd Configure Ack #3 (Req-Sent) Mar 18 12:17:00 ppp [wan_link0] MRU 1492 Mar 18 12:17:00 ppp [wan_link0] MAGICNUM 0xf9XXXXX Mar 18 12:17:00 ppp [wan_link0] LCP: state change Req-Sent --> Ack-Rcvd Mar 18 12:17:01 ppp [wan_link0] LCP: rec'd Configure Request #126 (Ack-Rcvd) Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] AUTHPROTO PAP Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0x5fXXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: SendConfigAck #126 Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] AUTHPROTO PAP Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0x5fXXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: state change Ack-Rcvd --> Opened Mar 18 12:17:01 ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing Mar 18 12:17:01 ppp [wan_link0] PAP: using authname "XXXXXX@XXXXXX.ca" Mar 18 12:17:01 ppp [wan_link0] PAP: sending REQUEST #1 len: 33 Mar 18 12:17:01 ppp [wan_link0] LCP: LayerUp Mar 18 12:17:01 ppp [wan_link0] LCP: rec'd Configure Request #75 (Opened) Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] AUTHPROTO PAP Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0x10XXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: LayerDown Mar 18 12:17:01 ppp [wan_link0] LCP: SendConfigReq #4 Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0xf9XXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: SendConfigAck #75 Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] AUTHPROTO PAP Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0x10XXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: state change Opened --> Ack-Sent Mar 18 12:17:01 ppp [wan_link0] LCP: rec'd Configure Ack #4 (Ack-Sent) Mar 18 12:17:01 ppp [wan_link0] MRU 1492 Mar 18 12:17:01 ppp [wan_link0] MAGICNUM 0xXXXXXXX Mar 18 12:17:01 ppp [wan_link0] LCP: state change Ack-Sent --> Opened Mar 18 12:17:01 ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing Mar 18 12:17:01 ppp [wan_link0] PAP: using authname "XXXXXX@XXXXXX.ca" Mar 18 12:17:01 ppp [wan_link0] PAP: sending REQUEST #1 len: 33 Mar 18 12:17:01 ppp [wan_link0] LCP: LayerUp Mar 18 12:17:01 ppp [wan_link0] PAP: rec'd ACK #1 len: 5 Mar 18 12:17:01 ppp [wan_link0] LCP: authorization successful Mar 18 12:17:01 ppp [wan_link0] Link: Matched action 'bundle "wan" ""' Mar 18 12:17:01 ppp [wan_link0] Link: Join bundle "wan" Mar 18 12:17:01 ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps Mar 18 12:17:01 ppp [wan] IPCP: Open event Mar 18 12:17:01 ppp [wan] IPCP: state change Initial --> Starting Mar 18 12:17:01 ppp [wan] IPCP: LayerStart Mar 18 12:17:01 ppp [wan] IPV6CP: Open event Mar 18 12:17:01 ppp [wan] IPV6CP: state change Initial --> Starting Mar 18 12:17:01 ppp [wan] IPV6CP: LayerStart Mar 18 12:17:01 ppp [wan] IPCP: Up event Mar 18 12:17:01 ppp [wan] IPCP: state change Starting --> Req-Sent Mar 18 12:17:01 ppp [wan] IPCP: SendConfigReq #1 Mar 18 12:17:01 ppp [wan] IPADDR 0.0.0.0 Mar 18 12:17:01 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Mar 18 12:17:01 ppp [wan] PRIDNS 0.0.0.0 Mar 18 12:17:01 ppp [wan] SECDNS 0.0.0.0 Mar 18 12:17:01 ppp [wan] IPV6CP: Up event Mar 18 12:17:01 ppp [wan] IPV6CP: state change Starting --> Req-Sent Mar 18 12:17:01 ppp [wan] IPV6CP: SendConfigReq #1 Mar 18 12:17:01 ppp [wan] IPCP: rec'd Configure Request #235 (Req-Sent) Mar 18 12:17:01 ppp [wan] IPADDR x.x.x.190 Mar 18 12:17:01 ppp [wan] x.x.x.190 is OK Mar 18 12:17:01 ppp [wan] IPCP: SendConfigAck #235 Mar 18 12:17:01 ppp [wan] IPADDR x.x.x.190 Mar 18 12:17:01 ppp [wan] IPCP: state change Req-Sent --> Ack-Sent Mar 18 12:17:01 ppp [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent) Mar 18 12:17:01 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Mar 18 12:17:01 ppp [wan] IPCP: SendConfigReq #2 Mar 18 12:17:01 ppp [wan] IPADDR 0.0.0.0 Mar 18 12:17:01 ppp [wan] PRIDNS 0.0.0.0 Mar 18 12:17:01 ppp [wan] SECDNS 0.0.0.0 Mar 18 12:17:01 ppp [wan_link0] LCP: rec'd Protocol Reject #76 (Opened) Mar 18 12:17:01 ppp [wan_link0] LCP: protocol IPV6CP was rejected Mar 18 12:17:01 ppp [wan] IPV6CP: protocol was rejected by peer Mar 18 12:17:01 ppp [wan] IPV6CP: state change Req-Sent --> Stopped Mar 18 12:17:01 ppp [wan] IPV6CP: LayerFinish Mar 18 12:17:01 ppp [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent) Mar 18 12:17:01 ppp [wan] IPADDR x.x.x.42 Mar 18 12:17:01 ppp [wan] x.x.x.42 is OK Mar 18 12:17:01 ppp [wan] PRIDNS x.x.x.193 Mar 18 12:17:01 ppp [wan] SECDNS x.x.x.129 Mar 18 12:17:01 ppp [wan] IPCP: SendConfigReq #3 Mar 18 12:17:01 ppp [wan] IPADDR x.x.x.42 Mar 18 12:17:01 ppp [wan] PRIDNS x.x.x.193 Mar 18 12:17:01 ppp [wan] SECDNS x.x.x.129 Mar 18 12:17:01 ppp [wan_link0] rec'd unexpected protocol IP Mar 18 12:17:01 ppp [wan_link0] rec'd unexpected protocol IP Mar 18 12:17:01 ppp [wan_link0] rec'd unexpected protocol IP Mar 18 12:17:01 ppp [wan_link0] rec'd unexpected protocol IP Mar 18 12:17:02 ppp [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent) Mar 18 12:17:02 ppp [wan] IPADDR x.x.x.42 Mar 18 12:17:02 ppp [wan] PRIDNS x.x.x.193 Mar 18 12:17:02 ppp [wan] SECDNS x.x.x.129 Mar 18 12:17:02 ppp [wan] IPCP: state change Ack-Sent --> Opened Mar 18 12:17:02 ppp [wan] IPCP: LayerUp Mar 18 12:17:02 ppp [wan] x.x.x.42 -> x.x.x.190 Mar 18 12:17:02 check_reload_status Rewriting resolv.conf Mar 18 12:17:03 check_reload_status rc.newwanip starting pppoe0 Mar 18 12:17:03 ppp [wan] IFACE: Up event Mar 18 12:17:03 ppp [wan] IFACE: Rename interface ng0 to pppoe0 Mar 18 12:17:04 php-fpm /rc.newwanip: rc.newwanip: Info: starting on pppoe0. Mar 18 12:17:04 php-fpm /rc.newwanip: rc.newwanip: on (IP address: x.x.x.42) (interface: WAN[wan]) (real interface: pppoe0). Mar 18 12:17:04 php-fpm /rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through x.x.x.190 Mar 18 12:17:04 php-fpm /rc.newwanip: Default gateway setting Interface WAN_PPPOE Gateway as default. Mar 18 12:17:04 php-fpm /rc.newwanip: Gateway, none 'available' for inet6, use the first one configured. '' Mar 18 12:17:08 php-fpm /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Mar 18 12:17:08 php-fpm OpenVPN terminate old pid: 38085 Mar 18 12:17:08 kernel ovpns1: link state changed to DOWN Mar 18 12:17:08 check_reload_status Reloading filter Mar 18 12:17:08 kernel ovpns1: link state changed to UP Mar 18 12:17:08 php-fpm OpenVPN PID written: 56318 Mar 18 12:17:08 check_reload_status Reloading filter Mar 18 12:17:08 php-fpm /rc.newwanip: Creating rrd update script Mar 18 12:17:08 check_reload_status rc.newwanip starting ovpns1 Mar 18 12:17:09 php-fpm /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Mar 18 12:17:09 php-fpm /rc.newwanip: rc.newwanip: on (IP address: 10.x.x.1) (interface: []) (real interface: ovpns1). Mar 18 12:17:09 php-fpm /rc.newwanip: rc.newwanip called with empty interface. Mar 18 12:17:09 check_reload_status Reloading filter Mar 18 12:17:09 php-fpm /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 10.x.x.1 - Restarting packages. Mar 18 12:17:09 check_reload_status Starting packages Mar 18 12:17:10 php-fpm /rc.start_packages: Restarting/Starting all packages. Mar 18 12:17:10 php-fpm /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - x.x.x.42 -> x.x.x.42 - Restarting packages. Mar 18 12:17:10 check_reload_status Starting packages Mar 18 12:17:11 php-fpm /rc.start_packages: Restarting/Starting all packages.
-
@Chrischevy , what pfsense packages did you install?
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.