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

    [Solved] PPPoE doesnt get renewed after link loss in 22.05

    General pfSense Questions
    2
    4
    492
    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.
    • T
      trumee
      last edited by trumee

      Hello,
      I have upgraded to 22.05 and noticed that PPPoE doesnt get renewed any more. My ISP uses PPPoE on a dumb fiber ONU. Here is the log

      #date
Tue Jul 12 08:38:11 

# cat /var/log/ppp.log
Jul 11 15:07:13 pfSense ppp[29306]: Multi-link PPP daemon for FreeBSD
Jul 11 15:07:13 pfSense ppp[29306]:  
Jul 11 15:07:13 pfSense ppp[29306]: process 29306 started, version 5.9
Jul 11 15:07:13 pfSense ppp[29306]: web: web is not running
Jul 11 15:07:13 pfSense ppp[29306]: [opt2] Bundle: Interface ng0 created
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] Link: OPEN event
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: Open event
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: state change Initial --> Starting
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: LayerStart
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] PPPoE: Connecting to ''
Jul 11 15:07:13 pfSense ppp[29306]: PPPoE: rec'd ACNAME "MYISP"
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] PPPoE: connection successful
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] Link: UP event
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: Up event
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: state change Starting --> Req-Sent
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: SendConfigReq #1
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   PROTOCOMP
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MRU 1492
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MAGICNUM 0xe31c7324
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: rec'd Configure Request #32 (Req-Sent)
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   AUTHPROTO CHAP MD5
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MRU 1492
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MAGICNUM 0x3a9dfacd
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: SendConfigAck #32
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   AUTHPROTO CHAP MD5
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MRU 1492
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MAGICNUM 0x3a9dfacd
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: state change Req-Sent --> Ack-Sent
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   PROTOCOMP
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: SendConfigReq #2
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MRU 1492
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MAGICNUM 0xe31c7324
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   Wrong id#, expecting 2
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] rec'd proto CHAP during establishment phase
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MRU 1492
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0]   MAGICNUM 0xe31c7324
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: state change Ack-Sent --> Opened
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: auth: peer wants CHAP, I want nothing
Jul 11 15:07:13 pfSense ppp[29306]: [opt2_link0] LCP: LayerUp
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] CHAP: rec'd CHALLENGE #1 len: 21
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0]   Name: ""
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] CHAP: Using authname "5281_kamla"
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] CHAP: sending RESPONSE #1 len: 31
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] CHAP: rec'd SUCCESS #1 len: 28
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0]   MESG: Authentication succeeded
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] LCP: authorization successful
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] Link: Matched action 'bundle "opt2" ""'
Jul 11 15:07:18 pfSense ppp[29306]: [opt2_link0] Link: Join bundle "opt2"
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: Open event
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: state change Initial --> Starting
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: LayerStart
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: Up event
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: state change Starting --> Req-Sent
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: SendConfigReq #1
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   PRIDNS 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   SECDNS 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: rec'd Configure Request #19 (Req-Sent)
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 104.120.50.3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]     104.120.50.3 is OK
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: SendConfigAck #19
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 104.120.50.3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: state change Req-Sent --> Ack-Sent
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: SendConfigReq #2
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   PRIDNS 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   SECDNS 0.0.0.0
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 10.40.66.192
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]     10.40.66.192 is OK
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: SendConfigReq #3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 10.40.66.192
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   IPADDR 10.40.66.192
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: state change Ack-Sent --> Opened
Jul 11 15:07:18 pfSense ppp[29306]: [opt2] IPCP: LayerUp
Jul 11 15:07:18 pfSense ppp[29306]: [opt2]   10.40.66.192 -> 104.120.50.3
Jul 11 15:07:19 pfSense ppp[29306]: [opt2] IFACE: Up event
Jul 11 15:07:19 pfSense ppp[29306]: [opt2] IFACE: Rename interface ng0 to pppoe2
Jul 11 15:07:19 pfSense ppp[29306]: [opt2] IFACE: Add description "WAN3"
Jul 11 15:07:33 pfSense ppp[75801]: Multi-link PPP daemon for FreeBSD
Jul 11 15:07:33 pfSense ppp[75801]:  
Jul 11 15:07:33 pfSense ppp[75801]: process 75801 started, version 5.9
Jul 11 15:07:33 pfSense ppp[75801]: waiting for process 29306 to die...
Jul 11 15:07:33 pfSense ppp[29306]: caught fatal signal TERM
Jul 11 15:07:33 pfSense ppp[29306]: [opt2] IFACE: Close event
Jul 11 15:07:33 pfSense ppp[29306]: [opt2] IPCP: Close event
Jul 11 15:07:33 pfSense ppp[29306]: [opt2] IPCP: state change Opened --> Closing
Jul 11 15:07:33 pfSense ppp[29306]: [opt2] IPCP: SendTerminateReq #4
Jul 11 15:07:33 pfSense ppp[29306]: [opt2] IPCP: LayerDown
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IFACE: Removing IPv4 address from pppoe2 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IFACE: Down event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IFACE: Rename interface pppoe2 to pppoe2
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IFACE: Set description "WAN3"
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: rec'd Terminate Request #21 (Closing)
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: SendTerminateAck #5
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: rec'd Terminate Ack #4 (Closing)
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: state change Closing --> Closed
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: LayerFinish
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] Bundle: No NCPs left. Closing links...
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] Bundle: closing link "opt2_link0"...
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: rec'd Terminate Request #34 (Opened)
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: state change Opened --> Stopping
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] Link: Leave bundle "opt2"
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: Close event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: Down event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2] IPCP: state change Closed --> Initial
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: SendTerminateAck #3
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: LayerDown
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] Link: CLOSE event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: Close event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: state change Stopping --> Closing
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] PPPoE: connection closed
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] Link: DOWN event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: Down event
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: LayerFinish
Jul 11 15:07:34 pfSense ppp[29306]: [opt2_link0] LCP: state change Closing --> Initial
Jul 11 15:07:34 pfSense ppp[75801]: waiting for process 29306 to die...
Jul 11 15:07:35 pfSense ppp[75801]: waiting for process 29306 to die...
Jul 11 15:07:36 pfSense ppp[29306]: [opt2] Bundle: Shutdown
Jul 11 15:07:36 pfSense ppp[29306]: [opt2_link0] Link: Shutdown
Jul 11 15:07:36 pfSense ppp[29306]: process 29306 terminated
Jul 11 15:07:36 pfSense ppp[75801]: web: web is not running
Jul 11 15:07:36 pfSense ppp[75801]: [opt2] Bundle: Interface ng0 created
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] Link: OPEN event
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: Open event
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: state change Initial --> Starting
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: LayerStart
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] PPPoE: Connecting to ''
Jul 11 15:07:36 pfSense ppp[75801]: PPPoE: rec'd ACNAME "MYISP"
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] PPPoE: connection successful
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] Link: UP event
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: Up event
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: state change Starting --> Req-Sent
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: SendConfigReq #1
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   PROTOCOMP
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MRU 1492
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MAGICNUM 0xee9d1da9
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: rec'd Configure Request #141 (Req-Sent)
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   AUTHPROTO CHAP MD5
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MRU 1492
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MAGICNUM 0x58bffcd0
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: SendConfigAck #141
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   AUTHPROTO CHAP MD5
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MRU 1492
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MAGICNUM 0x58bffcd0
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: state change Req-Sent --> Ack-Sent
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   PROTOCOMP
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: SendConfigReq #2
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MRU 1492
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MAGICNUM 0xee9d1da9
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   Wrong id#, expecting 2
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] rec'd proto CHAP during establishment phase
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MRU 1492
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0]   MAGICNUM 0xee9d1da9
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: state change Ack-Sent --> Opened
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: auth: peer wants CHAP, I want nothing
Jul 11 15:07:36 pfSense ppp[75801]: [opt2_link0] LCP: LayerUp
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] CHAP: rec'd CHALLENGE #1 len: 21
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0]   Name: ""
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] CHAP: Using authname "5281_kamla"
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] CHAP: sending RESPONSE #1 len: 31
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] CHAP: rec'd SUCCESS #1 len: 28
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0]   MESG: Authentication succeeded
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] LCP: authorization successful
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] Link: Matched action 'bundle "opt2" ""'
Jul 11 15:07:41 pfSense ppp[75801]: [opt2_link0] Link: Join bundle "opt2"
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: Open event
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: state change Initial --> Starting
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: LayerStart
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: Up event
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: state change Starting --> Req-Sent
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: SendConfigReq #1
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   PRIDNS 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   SECDNS 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: rec'd Configure Request #92 (Req-Sent)
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 104.120.50.3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]     104.120.50.3 is OK
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: SendConfigAck #92
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 104.120.50.3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: state change Req-Sent --> Ack-Sent
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: SendConfigReq #2
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   PRIDNS 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   SECDNS 0.0.0.0
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 10.40.124.202
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]     10.40.124.202 is OK
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: SendConfigReq #3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 10.40.124.202
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   IPADDR 10.40.124.202
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   PRIDNS 104.120.50.3
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   SECDNS 104.120.50.244
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: state change Ack-Sent --> Opened
Jul 11 15:07:41 pfSense ppp[75801]: [opt2] IPCP: LayerUp
Jul 11 15:07:41 pfSense ppp[75801]: [opt2]   10.40.124.202 -> 104.120.50.3
Jul 11 15:07:42 pfSense ppp[75801]: [opt2] IFACE: Up event
Jul 11 15:07:42 pfSense ppp[75801]: [opt2] IFACE: Rename interface ng0 to pppoe2
Jul 11 15:07:42 pfSense ppp[75801]: [opt2] IFACE: Add description "WAN3"
Jul 12 00:58:47 pfSense ppp[75801]: caught fatal signal TERM
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IFACE: Close event
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IPCP: Close event
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IPCP: state change Opened --> Closing
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IPCP: SendTerminateReq #4
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] error writing len 8 frame to b0: Network is down
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IPCP: LayerDown
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IFACE: Removing IPv4 address from pppoe2 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IFACE: Down event
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IFACE: Rename interface pppoe2 to pppoe2
Jul 12 00:58:47 pfSense ppp[75801]: [opt2] IFACE: Set description "WAN3"
Jul 12 00:58:49 pfSense ppp[75801]: [opt2] IPCP: SendTerminateReq #5
Jul 12 00:58:49 pfSense ppp[75801]: [opt2] error writing len 8 frame to b0: Network is down
Jul 12 00:58:49 pfSense ppp[75801]: [opt2] Bundle: Shutdown
Jul 12 00:58:49 pfSense ppp[75801]: [opt2_link0] Link: Shutdown
Jul 12 00:58:49 pfSense ppp[75801]: process 75801 terminated

      The system log shows that the associated interface went down and then came up.

      # cat /var/log/system.log | grep ix2
Jul 12 00:58:46 pfSense check_reload_status[458]: Linkup starting ix2
Jul 12 00:58:46 pfSense kernel: ix2: link state changed to DOWN
Jul 12 00:58:49 pfSense kernel: ix2: link state changed to UP

      Notice the time of writing this post is 8:38am (date command above) and the last line in ppp.log is midnight. There is nothing in the log after that.

      1 Reply Last reply Reply Quote 0
      • stephenw10S
        stephenw10 Netgate Administrator
        last edited by

        What does the system log show during that time?
        Nothing other than those entries?

        I expect the ppp process to be restarted when the parent interface is relinked.

        Steve

        T 1 Reply Last reply Reply Quote 0
        • T trumee referenced this topic on
        • T
          trumee @stephenw10
          last edited by

          @stephenw10 I am going to give this another day of testing after removing this script.

          1 Reply Last reply Reply Quote 0
          • T
            trumee
            last edited by

            Indeed it was my wireguard script messing with this. Once i removed it, things are back to normal.

            1 Reply Last reply Reply Quote 1
            • First post
              Last post