Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    PPPoE disconnects few times a day for 20 seconds

    Scheduled Pinned Locked Moved General pfSense Questions
    2 Posts 2 Posters 164 Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • C
      Chrischevy
      last edited by

      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.
      
      1 Reply Last reply Reply Quote 0
      • AKEGECA
        AKEGEC
        last edited by

        @Chrischevy , what pfsense packages did you install?

        1 Reply Last reply Reply Quote 0
        • First post
          Last post
        Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.