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

    2.0.3 -> 2.1.3 : weird & unstable PPPOE link

    Scheduled Pinned Locked Moved Problems Installing or Upgrading pfSense Software
    8 Posts 3 Posters 3.3k 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.
    • P Offline
      phil242
      last edited by

      Hi,

      I experience problem with the PPPOE after a 2.0.3 -> 2.1.3 upgrade.

      I came from a rock stable 2.0.3, no xDSL link lost, 8 month uptime, in short working like a charm.

      Since upgrading to 2.1.3, it's really hard to maintain something up for 24H.

      Here is the today logs :

      May 26 03:27:06 ppp: caught fatal signal term
      May 26 03:27:06 ppp: [wan] IFACE: Close event
      May 26 03:27:06 ppp: [wan] IPCP: Close event
      May 26 03:27:06 ppp: [wan] IPCP: state change Opened –> Closing
      May 26 03:27:06 ppp: [wan] IPCP: SendTerminateReq #4
      May 26 03:27:06 ppp: [wan] IPCP: LayerDown
      May 26 03:27:06 ppp: [wan] IFACE: Delete route 0.0.0.0/0 yyy.yyy.yyy.yyy failed: No such process
      May 26 03:27:06 ppp: [wan] IFACE: Down event
      May 26 03:27:06 ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
      May 26 03:27:06 ppp: [wan] IPV6CP: Close event
      May 26 03:27:06 ppp: [wan] IPV6CP: state change Stopped –> Closed
      May 26 03:27:06 ppp: [wan] IPCP: rec'd Terminate Ack #4 (Closing)
      May 26 03:27:06 ppp: [wan] IPCP: state change Closing –> Closed
      May 26 03:27:06 ppp: [wan] IPCP: LayerFinish
      May 26 03:27:06 ppp: [wan] Bundle: No NCPs left. Closing links…
      May 26 03:27:06 ppp: [wan] Bundle: closing link "wan_link0"…
      May 26 03:27:06 ppp: [wan_link0] LCP: rec'd Terminate Request #74 (Opened)
      May 26 03:27:06 ppp: [wan_link0] LCP: state change Opened –> Stopping
      May 26 03:27:06 ppp: [wan_link0] Link: Leave bundle "wan"
      May 26 03:27:06 ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
      May 26 03:27:06 ppp: [wan] IPCP: Close event
      May 26 03:27:06 ppp: [wan] IPV6CP: Close event
      May 26 03:27:06 ppp: [wan] IPCP: Down event
      May 26 03:27:06 ppp: [wan] IPCP: state change Closed –> Initial
      May 26 03:27:06 ppp: [wan] IPV6CP: Down event
      May 26 03:27:06 ppp: [wan] IPV6CP: state change Closed –> Initial
      May 26 03:27:06 ppp: [wan_link0] LCP: SendTerminateAck #4
      May 26 03:27:06 ppp: [wan_link0] LCP: LayerDown
      May 26 03:27:06 ppp: [wan_link0] Link: CLOSE event
      May 26 03:27:06 ppp: [wan_link0] LCP: Close event
      May 26 03:27:06 ppp: [wan_link0] LCP: state change Stopping –> Closing
      May 26 03:27:06 ppp: Multi-link PPP daemon for FreeBSD
      May 26 03:27:06 ppp:
      May 26 03:27:06 ppp: process 69759 started, version 5.7 (root@snapshots-8_3-i386.builders.pfsense.org 19:47 27-Mar-2014)
      May 26 03:27:06 ppp: waiting for process 19830 to die...
      May 26 03:27:06 ppp: Multi-link PPP daemon for FreeBSD
      May 26 03:27:06 ppp:
      May 26 03:27:06 ppp: process 70280 started, version 5.7 (root@snapshots-8_3-i386.builders.pfsense.org 19:47 27-Mar-2014)
      May 26 03:27:06 ppp: waiting for process 19830 to die...
      May 26 03:27:07 ppp: waiting for process 19830 to die...
      May 26 03:27:07 ppp: waiting for process 19830 to die...
      May 26 03:27:08 ppp: [wan] Bundle: Shutdown
      May 26 03:27:08 ppp: [wan_link0] Link: Shutdown
      May 26 03:27:08 ppp: process 19830 terminated
      May 26 03:27:08 ppp: waiting for process 69759 to die…
      May 26 03:27:09 ppp: OpenConfFile: Can't open file '/var/etc/mpd_wan.conf': No such file or directory
      May 26 03:27:09 ppp: OpenConfFile: Can't open file '/var/etc/mpd_wan.conf': No such file or directory
      May 26 03:27:09 ppp: can't read configuration for "pppoeclient"
      May 26 03:27:09 ppp: process 70280 terminated

      --> Manually connect the PPP from web interface at 07:38

      May 26 07:38:04 ppp: Multi-link PPP daemon for FreeBSD
      May 26 07:38:04 ppp:
      May 26 07:38:04 ppp: process 5909 started, version 5.7 (root@snapshots-8_3-i386.builders.pfsense.org 19:47 27-Mar-2014)
      May 26 07:38:04 ppp: web: web is not running
      May 26 07:38:04 ppp: [wan] Bundle: Interface ng0 created
      May 26 07:38:04 ppp: [wan_link0] Link: OPEN event
      May 26 07:38:04 ppp: [wan_link0] LCP: Open event
      May 26 07:38:04 ppp: [wan_link0] LCP: state change Initial –> Starting
      May 26 07:38:04 ppp: [wan_link0] LCP: LayerStart
      May 26 07:38:04 ppp: [wan_link0] PPPoE: Connecting to ''
      May 26 07:38:04 ppp: PPPoE: rec'd ACNAME "SE1200-GNB-1"
      May 26 07:38:05 ppp: [wan_link0] PPPoE: connection successful
      May 26 07:38:05 ppp: [wan_link0] Link: UP event
      May 26 07:38:05 ppp: [wan_link0] LCP: Up event
      May 26 07:38:05 ppp: [wan_link0] LCP: state change Starting –> Req-Sent
      May 26 07:38:05 ppp: [wan_link0] LCP: SendConfigReq #1
      May 26 07:38:05 ppp: [wan_link0] PROTOCOMP
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 947e5b5c
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Configure Request #104 (Req-Sent)
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 231bf26b
      May 26 07:38:05 ppp: [wan_link0] LCP: SendConfigAck #104
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 231bf26b
      May 26 07:38:05 ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
      May 26 07:38:05 ppp: [wan_link0] PROTOCOMP
      May 26 07:38:05 ppp: [wan_link0] LCP: SendConfigReq #2
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 947e5b5c
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 947e5b5c
      May 26 07:38:05 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      May 26 07:38:05 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
      May 26 07:38:05 ppp: [wan_link0] LCP: LayerUp
      May 26 07:38:05 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 33
      May 26 07:38:05 ppp: [wan_link0] Name: "SE1200-GNB-1"
      May 26 07:38:05 ppp: [wan_link0] CHAP: Using authname "xxxxxxxxxxxxxxx"
      May 26 07:38:05 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Configure Request #65 (Opened)
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 231bf26b
      May 26 07:38:05 ppp: [wan_link0] LCP: LayerDown
      May 26 07:38:05 ppp: [wan_link0] LCP: SendConfigReq #3
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 947e5b5c
      May 26 07:38:05 ppp: [wan_link0] LCP: SendConfigAck #65
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 231bf26b
      May 26 07:38:05 ppp: [wan_link0] LCP: state change Opened –> Ack-Sent
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Configure Ack #3 (Ack-Sent)
      May 26 07:38:05 ppp: [wan_link0] MRU 1492
      May 26 07:38:05 ppp: [wan_link0] MAGICNUM 947e5b5c
      May 26 07:38:05 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      May 26 07:38:05 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
      May 26 07:38:05 ppp: [wan_link0] LCP: LayerUp
      May 26 07:38:05 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 37
      May 26 07:38:05 ppp: [wan_link0] Name: "lns-1-lyo-se1200"
      May 26 07:38:05 ppp: [wan_link0] CHAP: Using authname "xxxxxxxxxxxxxxx"
      May 26 07:38:05 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 07:38:05 ppp: [wan_link0] CHAP: rec'd SUCCESS #1 len: 42
      May 26 07:38:05 ppp: [wan_link0] MESG: CHAP authentication success, unit 1574
      May 26 07:38:05 ppp: [wan_link0] LCP: authorization successful
      May 26 07:38:05 ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
      May 26 07:38:05 ppp: [wan_link0] Link: Join bundle "wan"
      May 26 07:38:05 ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
      May 26 07:38:05 ppp: [wan] IPCP: Open event
      May 26 07:38:05 ppp: [wan] IPCP: state change Initial –> Starting
      May 26 07:38:05 ppp: [wan] IPCP: LayerStart
      May 26 07:38:05 ppp: [wan] IPV6CP: Open event
      May 26 07:38:05 ppp: [wan] IPV6CP: state change Initial –> Starting
      May 26 07:38:05 ppp: [wan] IPV6CP: LayerStart
      May 26 07:38:05 ppp: [wan] IPCP: Up event
      May 26 07:38:05 ppp: [wan] IPCP: state change Starting –> Req-Sent
      May 26 07:38:05 ppp: [wan] IPCP: SendConfigReq #1
      May 26 07:38:05 ppp: [wan] IPADDR 0.0.0.0
      May 26 07:38:05 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      May 26 07:38:05 ppp: [wan] PRIDNS 0.0.0.0
      May 26 07:38:05 ppp: [wan] SECDNS 0.0.0.0
      May 26 07:38:05 ppp: [wan] IPV6CP: Up event
      May 26 07:38:05 ppp: [wan] IPV6CP: state change Starting –> Req-Sent
      May 26 07:38:05 ppp: [wan] IPV6CP: SendConfigReq #1
      May 26 07:38:05 ppp: [wan] IPCP: rec'd Configure Request #132 (Req-Sent)
      May 26 07:38:05 ppp: [wan] IPADDR yyy.yyy.yyy.yyy
      May 26 07:38:05 ppp: [wan] yyy.yyy.yyy.yyy is OK
      May 26 07:38:05 ppp: [wan] IPCP: SendConfigAck #132
      May 26 07:38:05 ppp: [wan] IPADDR yyy.yyy.yyy.yyy
      May 26 07:38:05 ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
      May 26 07:38:05 ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
      May 26 07:38:05 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      May 26 07:38:05 ppp: [wan] IPCP: SendConfigReq #2
      May 26 07:38:05 ppp: [wan] IPADDR 0.0.0.0
      May 26 07:38:05 ppp: [wan] PRIDNS 0.0.0.0
      May 26 07:38:05 ppp: [wan] SECDNS 0.0.0.0
      May 26 07:38:05 ppp: [wan_link0] LCP: rec'd Protocol Reject #66 (Opened)
      May 26 07:38:05 ppp: [wan_link0] LCP: protocol IPV6CP was rejected
      May 26 07:38:05 ppp: [wan] IPV6CP: protocol was rejected by peer
      May 26 07:38:05 ppp: [wan] IPV6CP: state change Req-Sent –> Stopped
      May 26 07:38:05 ppp: [wan] IPV6CP: LayerFinish
      May 26 07:38:05 ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
      May 26 07:38:05 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 07:38:05 ppp: [wan] xxx.xxx.xxx.xxx is OK
      May 26 07:38:05 ppp: [wan] PRIDNS 91.121.161.184
      May 26 07:38:05 ppp: [wan] SECDNS 188.165.197.144
      May 26 07:38:05 ppp: [wan] IPCP: SendConfigReq #3
      May 26 07:38:05 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 07:38:05 ppp: [wan] PRIDNS 91.121.161.184
      May 26 07:38:05 ppp: [wan] SECDNS 188.165.197.144
      May 26 07:38:05 ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
      May 26 07:38:05 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 07:38:05 ppp: [wan] PRIDNS 91.121.161.184
      May 26 07:38:05 ppp: [wan] SECDNS 188.165.197.144
      May 26 07:38:05 ppp: [wan] IPCP: state change Ack-Sent –> Opened
      May 26 07:38:05 ppp: [wan] IPCP: LayerUp
      May 26 07:38:05 ppp: [wan] xxx.xxx.xxx.xxx -> yyy.yyy.yyy.yyy
      May 26 07:38:06 ppp: [wan] IFACE: Up event
      May 26 07:38:06 ppp: [wan] IFACE: Rename interface ng0 to pppoe0
      May 26 16:23:30 ppp: caught fatal signal term
      May 26 16:23:30 ppp: [wan] IFACE: Close event
      May 26 16:23:30 ppp: [wan] IPCP: Close event
      May 26 16:23:30 ppp: [wan] IPCP: state change Opened –> Closing
      May 26 16:23:30 ppp: [wan] IPCP: SendTerminateReq #4
      May 26 16:23:30 ppp: [wan] IPCP: LayerDown
      May 26 16:23:31 ppp: [wan] IFACE: Delete route 0.0.0.0/0 yyy.yyy.yyy.yyy failed: No such process
      May 26 16:23:31 ppp: [wan] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
      May 26 16:23:31 ppp: [wan] IFACE: Down event
      May 26 16:23:31 ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
      May 26 16:23:31 ppp: [wan] IPV6CP: Close event
      May 26 16:23:31 ppp: [wan] IPV6CP: state change Stopped –> Closed
      May 26 16:23:31 ppp: [wan] IPCP: rec'd Terminate Ack #4 (Closing)
      May 26 16:23:31 ppp: [wan] IPCP: state change Closing –> Closed
      May 26 16:23:31 ppp: [wan] IPCP: LayerFinish
      May 26 16:23:31 ppp: [wan] Bundle: No NCPs left. Closing links…
      May 26 16:23:31 ppp: [wan] Bundle: closing link "wan_link0"…
      May 26 16:23:31 ppp: [wan_link0] LCP: rec'd Terminate Request #67 (Opened)
      May 26 16:23:31 ppp: [wan_link0] LCP: state change Opened –> Stopping
      May 26 16:23:31 ppp: [wan_link0] Link: Leave bundle "wan"
      May 26 16:23:31 ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
      May 26 16:23:31 ppp: [wan] IPCP: Close event
      May 26 16:23:31 ppp: [wan] IPV6CP: Close event
      May 26 16:23:31 ppp: [wan] IPCP: Down event
      May 26 16:23:31 ppp: [wan] IPCP: state change Closed –> Initial
      May 26 16:23:31 ppp: [wan] IPV6CP: Down event
      May 26 16:23:31 ppp: [wan] IPV6CP: state change Closed –> Initial
      May 26 16:23:31 ppp: [wan_link0] LCP: SendTerminateAck #4
      May 26 16:23:31 ppp: [wan_link0] LCP: LayerDown
      May 26 16:23:31 ppp: [wan_link0] Link: CLOSE event
      May 26 16:23:31 ppp: [wan_link0] LCP: Close event
      May 26 16:23:31 ppp: [wan_link0] LCP: state change Stopping –> Closing
      May 26 16:23:31 ppp: Multi-link PPP daemon for FreeBSD
      May 26 16:23:31 ppp:
      May 26 16:23:31 ppp: process 19539 started, version 5.7 (root@snapshots-8_3-i386.builders.pfsense.org 19:47 27-Mar-2014)
      May 26 16:23:31 ppp: waiting for process 5909 to die...
      May 26 16:23:32 ppp: waiting for process 5909 to die...
      May 26 16:23:33 ppp: waiting for process 5909 to die...
      May 26 16:23:33 ppp: [wan_link0] LCP: state change Closing –> Closed
      May 26 16:23:33 ppp: [wan_link0] LCP: LayerFinish
      May 26 16:23:33 ppp: [wan] Bundle: Shutdown
      May 26 16:23:33 ppp: [wan_link0] Link: Shutdown
      May 26 16:23:33 ppp: process 5909 terminated
      May 26 16:23:34 ppp: OpenConfFile: Can't open file '/var/etc/mpd_wan.conf': No such file or directory
      May 26 16:23:34 ppp: OpenConfFile: Can't open file '/var/etc/mpd_wan.conf': No such file or directory
      May 26 16:23:34 ppp: can't read configuration for "pppoeclient"
      May 26 16:23:34 ppp: process 19539 terminated

      –> here, no internet cnx, no action from me, PfSense brings back the PPP at 17h31

      May 26 17:31:33 ppp: Multi-link PPP daemon for FreeBSD
      May 26 17:31:33 ppp:
      May 26 17:31:33 ppp: process 34353 started, version 5.7 (root@snapshots-8_3-i386.builders.pfsense.org 19:47 27-Mar-2014)
      May 26 17:31:33 ppp: web: web is not running
      May 26 17:31:33 ppp: [wan] Bundle: Interface ng0 created
      May 26 17:31:33 ppp: [wan_link0] Link: OPEN event
      May 26 17:31:33 ppp: [wan_link0] LCP: Open event
      May 26 17:31:33 ppp: [wan_link0] LCP: state change Initial –> Starting
      May 26 17:31:33 ppp: [wan_link0] LCP: LayerStart
      May 26 17:31:33 ppp: [wan_link0] PPPoE: Connecting to ''
      May 26 17:31:33 ppp: PPPoE: rec'd ACNAME "SE1200-GNB-1"
      May 26 17:31:33 ppp: [wan_link0] PPPoE: connection successful
      May 26 17:31:33 ppp: [wan_link0] Link: UP event
      May 26 17:31:33 ppp: [wan_link0] LCP: Up event
      May 26 17:31:33 ppp: [wan_link0] LCP: state change Starting –> Req-Sent
      May 26 17:31:33 ppp: [wan_link0] LCP: SendConfigReq #1
      May 26 17:31:33 ppp: [wan_link0] PROTOCOMP
      May 26 17:31:33 ppp: [wan_link0] MRU 1492
      May 26 17:31:33 ppp: [wan_link0] MAGICNUM d7851407
      May 26 17:31:33 ppp: [wan_link0] LCP: rec'd Configure Request #238 (Req-Sent)
      May 26 17:31:33 ppp: [wan_link0] MRU 1492
      May 26 17:31:33 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:33 ppp: [wan_link0] MAGICNUM 3faac796
      May 26 17:31:33 ppp: [wan_link0] LCP: SendConfigAck #238
      May 26 17:31:33 ppp: [wan_link0] MRU 1492
      May 26 17:31:33 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:33 ppp: [wan_link0] MAGICNUM 3faac796
      May 26 17:31:33 ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
      May 26 17:31:33 ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
      May 26 17:31:33 ppp: [wan_link0] PROTOCOMP
      May 26 17:31:33 ppp: [wan_link0] LCP: SendConfigReq #2
      May 26 17:31:33 ppp: [wan_link0] MRU 1492
      May 26 17:31:33 ppp: [wan_link0] MAGICNUM d7851407
      May 26 17:31:34 ppp: [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
      May 26 17:31:34 ppp: [wan_link0] MRU 1492
      May 26 17:31:34 ppp: [wan_link0] MAGICNUM d7851407
      May 26 17:31:34 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      May 26 17:31:34 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
      May 26 17:31:34 ppp: [wan_link0] LCP: LayerUp
      May 26 17:31:34 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 33
      May 26 17:31:34 ppp: [wan_link0] Name: "SE1200-GNB-1"
      May 26 17:31:34 ppp: [wan_link0] CHAP: Using authname "xxxxxxxxxxxxxxx"
      May 26 17:31:34 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 17:31:36 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 17:31:36 ppp: [wan_link0] CHAP: rec'd FAILURE #1 len: 18
      May 26 17:31:36 ppp: [wan_link0] MESG: Request Denied
      May 26 17:31:36 ppp: [wan_link0] LCP: authorization failed
      May 26 17:31:36 ppp: [wan_link0] LCP: parameter negotiation failed
      May 26 17:31:36 ppp: [wan_link0] LCP: state change Opened –> Stopping
      May 26 17:31:36 ppp: [wan_link0] LCP: SendTerminateReq #3
      May 26 17:31:36 ppp: [wan_link0] LCP: LayerDown
      May 26 17:31:36 ppp: [wan_link0] LCP: rec'd Terminate Request #239 (Stopping)
      May 26 17:31:36 ppp: [wan_link0] LCP: SendTerminateAck #4
      May 26 17:31:36 ppp: [wan_link0] LCP: rec'd Terminate Ack #3 (Stopping)
      May 26 17:31:36 ppp: [wan_link0] LCP: state change Stopping –> Stopped
      May 26 17:31:36 ppp: [wan_link0] LCP: LayerFinish
      May 26 17:31:36 ppp: [wan_link0] PPPoE: connection closed
      May 26 17:31:36 ppp: [wan_link0] Link: DOWN event
      May 26 17:31:36 ppp: [wan_link0] LCP: Down event
      May 26 17:31:36 ppp: [wan_link0] LCP: state change Stopped –> Starting
      May 26 17:31:36 ppp: [wan_link0] LCP: LayerStart
      May 26 17:31:36 ppp: [wan_link0] Link: reconnection attempt 1 in 4 seconds
      May 26 17:31:40 ppp: [wan_link0] Link: reconnection attempt 1
      May 26 17:31:40 ppp: [wan_link0] PPPoE: Connecting to ''
      May 26 17:31:40 ppp: PPPoE: rec'd ACNAME "SE1200-GNB-1"
      May 26 17:31:40 ppp: [wan_link0] PPPoE: connection successful
      May 26 17:31:40 ppp: [wan_link0] Link: UP event
      May 26 17:31:40 ppp: [wan_link0] LCP: Up event
      May 26 17:31:40 ppp: [wan_link0] LCP: state change Starting –> Req-Sent
      May 26 17:31:40 ppp: [wan_link0] LCP: SendConfigReq #5
      May 26 17:31:40 ppp: [wan_link0] PROTOCOMP
      May 26 17:31:40 ppp: [wan_link0] MRU 1492
      May 26 17:31:40 ppp: [wan_link0] MAGICNUM 95865b7f
      May 26 17:31:40 ppp: [wan_link0] LCP: rec'd Configure Request #128 (Req-Sent)
      May 26 17:31:40 ppp: [wan_link0] MRU 1492
      May 26 17:31:40 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:40 ppp: [wan_link0] MAGICNUM 63590dca
      May 26 17:31:40 ppp: [wan_link0] LCP: SendConfigAck #128
      May 26 17:31:40 ppp: [wan_link0] MRU 1492
      May 26 17:31:40 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:40 ppp: [wan_link0] MAGICNUM 63590dca
      May 26 17:31:40 ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
      May 26 17:31:40 ppp: [wan_link0] LCP: rec'd Configure Reject #5 (Ack-Sent)
      May 26 17:31:40 ppp: [wan_link0] PROTOCOMP
      May 26 17:31:40 ppp: [wan_link0] LCP: SendConfigReq #6
      May 26 17:31:40 ppp: [wan_link0] MRU 1492
      May 26 17:31:40 ppp: [wan_link0] MAGICNUM 95865b7f
      May 26 17:31:40 ppp: [wan_link0] LCP: rec'd Configure Ack #6 (Ack-Sent)
      May 26 17:31:40 ppp: [wan_link0] MRU 1492
      May 26 17:31:40 ppp: [wan_link0] MAGICNUM 95865b7f
      May 26 17:31:40 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      May 26 17:31:40 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
      May 26 17:31:40 ppp: [wan_link0] LCP: LayerUp
      May 26 17:31:40 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 33
      May 26 17:31:40 ppp: [wan_link0] Name: "SE1200-GNB-1"
      May 26 17:31:40 ppp: [wan_link0] CHAP: Using authname "xxxxxxxxxxxxxxx"
      May 26 17:31:40 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 17:31:41 ppp: [wan_link0] LCP: rec'd Configure Request #54 (Opened)
      May 26 17:31:41 ppp: [wan_link0] MRU 1492
      May 26 17:31:41 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:41 ppp: [wan_link0] MAGICNUM 63590dca
      May 26 17:31:41 ppp: [wan_link0] LCP: LayerDown
      May 26 17:31:41 ppp: [wan_link0] LCP: SendConfigReq #7
      May 26 17:31:41 ppp: [wan_link0] MRU 1492
      May 26 17:31:41 ppp: [wan_link0] MAGICNUM 95865b7f
      May 26 17:31:41 ppp: [wan_link0] LCP: SendConfigAck #54
      May 26 17:31:41 ppp: [wan_link0] MRU 1492
      May 26 17:31:41 ppp: [wan_link0] AUTHPROTO CHAP MD5
      May 26 17:31:41 ppp: [wan_link0] MAGICNUM 63590dca
      May 26 17:31:41 ppp: [wan_link0] LCP: state change Opened –> Ack-Sent
      May 26 17:31:41 ppp: [wan_link0] LCP: rec'd Configure Ack #7 (Ack-Sent)
      May 26 17:31:41 ppp: [wan_link0] MRU 1492
      May 26 17:31:41 ppp: [wan_link0] MAGICNUM 95865b7f
      May 26 17:31:41 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      May 26 17:31:41 ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
      May 26 17:31:41 ppp: [wan_link0] LCP: LayerUp
      May 26 17:31:41 ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 37
      May 26 17:31:41 ppp: [wan_link0] Name: "lns-1-lyo-se1200"
      May 26 17:31:41 ppp: [wan_link0] CHAP: Using authname "xxxxxxxxxxxxxxx"
      May 26 17:31:41 ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 42
      May 26 17:31:41 ppp: [wan_link0] CHAP: rec'd SUCCESS #1 len: 42
      May 26 17:31:41 ppp: [wan_link0] MESG: CHAP authentication success, unit 3270
      May 26 17:31:41 ppp: [wan_link0] LCP: authorization successful
      May 26 17:31:41 ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
      May 26 17:31:41 ppp: [wan_link0] Link: Join bundle "wan"
      May 26 17:31:41 ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
      May 26 17:31:41 ppp: [wan] IPCP: Open event
      May 26 17:31:41 ppp: [wan] IPCP: state change Initial –> Starting
      May 26 17:31:41 ppp: [wan] IPCP: LayerStart
      May 26 17:31:41 ppp: [wan] IPV6CP: Open event
      May 26 17:31:41 ppp: [wan] IPV6CP: state change Initial –> Starting
      May 26 17:31:41 ppp: [wan] IPV6CP: LayerStart
      May 26 17:31:41 ppp: [wan] IPCP: Up event
      May 26 17:31:41 ppp: [wan] IPCP: state change Starting –> Req-Sent
      May 26 17:31:41 ppp: [wan] IPCP: SendConfigReq #1
      May 26 17:31:41 ppp: [wan] IPADDR 0.0.0.0
      May 26 17:31:41 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      May 26 17:31:41 ppp: [wan] PRIDNS 0.0.0.0
      May 26 17:31:41 ppp: [wan] SECDNS 0.0.0.0
      May 26 17:31:41 ppp: [wan] IPV6CP: Up event
      May 26 17:31:41 ppp: [wan] IPV6CP: state change Starting –> Req-Sent
      May 26 17:31:41 ppp: [wan] IPV6CP: SendConfigReq #1
      May 26 17:31:41 ppp: [wan] IPCP: rec'd Configure Request #132 (Req-Sent)
      May 26 17:31:41 ppp: [wan] IPADDR yyy.yyy.yyy.yyy
      May 26 17:31:41 ppp: [wan] yyy.yyy.yyy.yyy is OK
      May 26 17:31:41 ppp: [wan] IPCP: SendConfigAck #132
      May 26 17:31:41 ppp: [wan] IPADDR yyy.yyy.yyy.yyy
      May 26 17:31:41 ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
      May 26 17:31:41 ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
      May 26 17:31:41 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      May 26 17:31:41 ppp: [wan] IPCP: SendConfigReq #2
      May 26 17:31:41 ppp: [wan] IPADDR 0.0.0.0
      May 26 17:31:41 ppp: [wan] PRIDNS 0.0.0.0
      May 26 17:31:41 ppp: [wan] SECDNS 0.0.0.0
      May 26 17:31:41 ppp: [wan_link0] LCP: rec'd Protocol Reject #55 (Opened)
      May 26 17:31:41 ppp: [wan_link0] LCP: protocol IPV6CP was rejected
      May 26 17:31:41 ppp: [wan] IPV6CP: protocol was rejected by peer
      May 26 17:31:41 ppp: [wan] IPV6CP: state change Req-Sent –> Stopped
      May 26 17:31:41 ppp: [wan] IPV6CP: LayerFinish
      May 26 17:31:41 ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
      May 26 17:31:41 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 17:31:41 ppp: [wan] xxx.xxx.xxx.xxx is OK
      May 26 17:31:41 ppp: [wan] PRIDNS 91.121.161.184
      May 26 17:31:41 ppp: [wan] SECDNS 188.165.197.144
      May 26 17:31:41 ppp: [wan] IPCP: SendConfigReq #3
      May 26 17:31:41 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 17:31:41 ppp: [wan] PRIDNS 91.121.161.184
      May 26 17:31:41 ppp: [wan] SECDNS 188.165.197.144
      May 26 17:31:41 ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
      May 26 17:31:41 ppp: [wan] IPADDR xxx.xxx.xxx.xxx
      May 26 17:31:41 ppp: [wan] PRIDNS 91.121.161.184
      May 26 17:31:41 ppp: [wan] SECDNS 188.165.197.144
      May 26 17:31:41 ppp: [wan] IPCP: state change Ack-Sent –> Opened
      May 26 17:31:41 ppp: [wan] IPCP: LayerUp
      May 26 17:31:41 ppp: [wan] xxx.xxx.xxx.xxx -> yyy.yyy.yyy.yyy
      May 26 17:31:42 ppp: [wan] IFACE: Up event
      May 26 17:31:42 ppp: [wan] IFACE: Rename interface ng0 to pppoe0

      I have tried to rise-up the threshold values of the WAN link, no effect.
      I have tried to disable "Hardware Checksum Offloading", no effect.
      Those 2 advices came from the forum & worth a try.

      I'm stuck on this one … Seems the PPP daemon gets mad, but I can't figure why.

      Would appreciate some helps on this one.

      Cheers,

      Phil

      1 Reply Last reply Reply Quote 0
      • V Offline
        val
        last edited by

        maybe try a fresh install of 2.1.3?

        Intel Xeon E3-1225 V2 @ 3.20Ghz
        Intel S1200KPR server board mini-ITX
        A-data ECC 4GB x 2 1600MHz
        Intel Ethernet Server Adapter I350-T2
        Samsung 840 Pro 120GB
        Lian-Li PC-Q15B

        1 Reply Last reply Reply Quote 0
        • P Offline
          phil242
          last edited by

          @val:

          maybe try a fresh install of 2.1.3?

          As the upgrade already trash the RRD graphs, yes I could do that  :). But according to my experience I bet this will not solve the problem …

          1 Reply Last reply Reply Quote 0
          • P Offline
            phil242
            last edited by

            I think my problem is not new & already referenced : https://redmine.pfsense.org/issues/1943

            How can I help to solve this one ? Need other logs, something to try ?

            1 Reply Last reply Reply Quote 0
            • C Offline
              clargentpfsense
              last edited by

              I am also experiencing this exact misbehavior at one of my client sites.

              Running 2.1.3-RELEASE (i386).

              We have a fairly solid radio link implemented, but inclement weather is periodically–and understandably--disrupting the PPPoE session.  Every single time the PPPoE session is disrupted, the pfSense device must be rebooted or somebody must log into the GUI and manually click the ‘Connect’ button.  Fortunately my client is being very understanding and patient.  Until this issue is resolved, we pray for clear skies!

              There is mention in the history of Bug #1943 that this issue may only be related to the ‘vr’ interface driver.  However, in my case, the interface driver is ‘bge’ (Broadcom).

              1 Reply Last reply Reply Quote 0
              • C Offline
                clargentpfsense
                last edited by

                As an aside, I upgraded my client’s appliance to 2.1.4-RELEASE (i386) and the problem persists.  Of course I really didn’t expect this latest security release to resolve our particular PPPoE issue.

                Based on everything I have read so far, this issue seems to be isolated to the “Embedded” (NanoBSD) edition of pfSense.  The Embedded edition of pfSense is optimized for hardware that uses any variation of flash memory as the system drive (as opposed to a traditional spindle hard drive).

                This morning I swapped in a different pfSense computer at my client…one that has a traditional hard drive, and thus is running the regular edition of pfSense.  As anticipated, it worked like a charm when I simulated a PPPoE interruption by simply disconnecting the cable to the WAN interface.  After I plugged the cable back in, pfSense was able to re-establish the PPPoE session in about 30 seconds.

                I know this test didn’t come close to abiding by the Scientific Method—many, many variables were changed at once.  Nevertheless, based on what I have read so far, I still feel the Embedded edition is highly suspect with respect to this PPPoE issue.

                1 Reply Last reply Reply Quote 0
                • P Offline
                  phil242
                  last edited by

                  Hi,

                  I run the "regular" version with an HDD & Squid proxy.
                  And in my case the problem appears with the upgrade from the 2.0.X to 2.1.X version.

                  To my guess (as scientific as ours :) ) it's more a kernel module version or something related who trig the bug.

                  I didn't solved it yet :(. And I have heavily play with this damn one …

                  Cheers,

                  Phil

                  1 Reply Last reply Reply Quote 0
                  • C Offline
                    clargentpfsense
                    last edited by

                    That’s a very helpful diagnostic, and I will no longer suspect the Embedded edition!

                    Given your input Phil, and now that I have an alternative pfSense appliance at my client site, I am going to completely re-install pfSense on my first device to see if the PPPoE problem is magically fixed by a fresh re-install.  I anticipate that a re-install will not fix the problem, but I want to put a nail in that coffin because it may be suggested or requested by a pfSense developer.

                    Out of curiosity Phil, what is the make of the WAN interface on your problematic unit (e.g., Intel, Broadcom, etc.)?  I may be overlooking this information in your PPP log.

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