4. Unable to establish PPPoE connection after upgrade to 2.3.4-RELEASE-p1

Unable to establish PPPoE connection after upgrade to 2.3.4-RELEASE-p1

  • J

    Hi,

    I’m from Malaysia and my ISP is TM Malaysia. I connect my pfsense with Streamyx PPPoE.

    My pfsense unable to establish PPPoE connection after upgrade to 2.3.4-RELEASE-p1.

    I tested again with 2.3.2-RELEASE and it works well.

    Please let me know if further info needed.

    Thank you.

    Below the log for the machine unable establish PPPoE.

    
Jul 21 09:30:47 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:30:47 ppp [opt2_link0] Link: reconnection attempt 27 
Jul 21 09:30:46 ppp [opt2_link0] Link: reconnection attempt 27 in 1 seconds 
Jul 21 09:30:46 ppp [opt2_link0] LCP: Down event 
Jul 21 09:30:46 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:30:46 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:30:37 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:30:37 ppp [opt2_link0] Link: reconnection attempt 26 
Jul 21 09:30:34 ppp [opt2_link0] Link: reconnection attempt 26 in 3 seconds 
Jul 21 09:30:34 ppp [opt2_link0] LCP: Down event 
Jul 21 09:30:34 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:30:34 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:30:25 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:30:25 ppp [opt2_link0] Link: reconnection attempt 25 
Jul 21 09:30:22 ppp [opt2_link0] Link: reconnection attempt 25 in 3 seconds 
Jul 21 09:30:22 ppp [opt2_link0] LCP: Down event 
Jul 21 09:30:22 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:30:22 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:30:13 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:30:13 ppp [opt2_link0] Link: reconnection attempt 24 
Jul 21 09:30:10 ppp [opt2_link0] Link: reconnection attempt 24 in 3 seconds 
Jul 21 09:30:10 ppp [opt2_link0] LCP: Down event 
Jul 21 09:30:10 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:30:10 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:30:01 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:30:01 ppp [opt2_link0] Link: reconnection attempt 23 
Jul 21 09:29:58 ppp [opt2_link0] Link: reconnection attempt 23 in 3 seconds 
Jul 21 09:29:58 ppp [opt2_link0] LCP: Down event 
Jul 21 09:29:58 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:29:58 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:29:49 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:29:49 ppp [opt2_link0] Link: reconnection attempt 22 
Jul 21 09:29:46 ppp [opt2_link0] Link: reconnection attempt 22 in 3 seconds 
Jul 21 09:29:46 ppp [opt2_link0] LCP: Down event 
Jul 21 09:29:46 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:29:46 ppp [opt2_link0] PPPoE connection timeout after 9 seconds 
Jul 21 09:29:37 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:29:37 ppp [opt2_link0] Link: reconnection attempt 21 
Jul 21 09:29:33 ppp [opt2_link0] Link: reconnection attempt 21 in 4 seconds 
Jul 21 09:29:33 ppp [opt2_link0] LCP: Down event 
Jul 21 09:29:33 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:29:33 ppp [opt2_link0] PPPoE connection timeout after 9 seconds

    Below the code for the machine able establish PPPoE connection.

    
Jul 21 09:27:54 ppp [opt2] 175.145.214.123 -> 175.145.214.254 
Jul 21 09:27:54 ppp [opt2] IPCP: LayerUp 
Jul 21 09:27:54 ppp [opt2] IPCP: state change Ack-Sent --> Opened 
Jul 21 09:27:54 ppp [opt2] IPADDR 175.145.214.123 
Jul 21 09:27:54 ppp [opt2] IPCP: rec'd Configure Ack #3 (Ack-Sent) 
Jul 21 09:27:54 ppp [opt2] IPADDR 175.145.214.123 
Jul 21 09:27:54 ppp [opt2] IPCP: SendConfigReq #3 
Jul 21 09:27:54 ppp [opt2] 175.145.214.123 is OK 
Jul 21 09:27:54 ppp [opt2] IPADDR 175.145.214.123 
Jul 21 09:27:54 ppp [opt2] IPCP: rec'd Configure Nak #2 (Ack-Sent) 
Jul 21 09:27:54 ppp [opt2] IFACE: Rename interface ng0 to pppoe0 
Jul 21 09:27:54 ppp [opt2] IFACE: Up event 
Jul 21 09:27:54 ppp [opt2] 0205:b7ff:fe08:ab13 -> 121b:54ff:fe83:5d57 
Jul 21 09:27:54 ppp [opt2] IPV6CP: LayerUp 
Jul 21 09:27:54 ppp [opt2] IPV6CP: state change Ack-Sent --> Opened 
Jul 21 09:27:54 ppp [opt2] IPV6CP: rec'd Configure Ack #1 (Ack-Sent) 
Jul 21 09:27:54 ppp [opt2] IPADDR 0.0.0.0 
Jul 21 09:27:54 ppp [opt2] IPCP: SendConfigReq #2 
Jul 21 09:27:54 ppp [opt2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 
Jul 21 09:27:54 ppp [opt2] IPCP: rec'd Configure Reject #1 (Ack-Sent) 
Jul 21 09:27:54 ppp [opt2] IPV6CP: state change Req-Sent --> Ack-Sent 
Jul 21 09:27:54 ppp [opt2] IPV6CP: SendConfigAck #1 
Jul 21 09:27:54 ppp [opt2] IPV6CP: rec'd Configure Request #1 (Req-Sent) 
Jul 21 09:27:54 ppp [opt2] IPCP: state change Req-Sent --> Ack-Sent 
Jul 21 09:27:54 ppp [opt2] IPADDR 175.145.214.254 
Jul 21 09:27:54 ppp [opt2] IPCP: SendConfigAck #1 
Jul 21 09:27:54 ppp [opt2] 175.145.214.254 is OK 
Jul 21 09:27:54 ppp [opt2] IPADDR 175.145.214.254 
Jul 21 09:27:54 ppp [opt2] IPCP: rec'd Configure Request #1 (Req-Sent) 
Jul 21 09:27:54 ppp [opt2] IPV6CP: SendConfigReq #1 
Jul 21 09:27:54 ppp [opt2] IPV6CP: state change Starting --> Req-Sent 
Jul 21 09:27:54 ppp [opt2] IPV6CP: Up event 
Jul 21 09:27:54 ppp [opt2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid 
Jul 21 09:27:54 ppp [opt2] IPADDR 0.0.0.0 
Jul 21 09:27:54 ppp [opt2] IPCP: SendConfigReq #1 
Jul 21 09:27:54 ppp [opt2] IPCP: state change Starting --> Req-Sent 
Jul 21 09:27:54 ppp [opt2] IPCP: Up event 
Jul 21 09:27:54 ppp [opt2] IPV6CP: LayerStart 
Jul 21 09:27:54 ppp [opt2] IPV6CP: state change Initial --> Starting 
Jul 21 09:27:54 ppp [opt2] IPV6CP: Open event 
Jul 21 09:27:54 ppp [opt2] IPCP: LayerStart 
Jul 21 09:27:54 ppp [opt2] IPCP: state change Initial --> Starting 
Jul 21 09:27:54 ppp [opt2] IPCP: Open event 
Jul 21 09:27:54 ppp [opt2] Bundle: Status update: up 1 link, total bandwidth 64000 bps 
Jul 21 09:27:54 ppp [opt2_link0] Link: Join bundle "opt2" 
Jul 21 09:27:54 ppp [opt2_link0] Link: Matched action 'bundle "opt2" ""' 
Jul 21 09:27:54 ppp [opt2_link0] LCP: authorization successful 
Jul 21 09:27:54 ppp [opt2_link0] MESG: Authentication success,Welcome! 
Jul 21 09:27:54 ppp [opt2_link0] PAP: rec'd ACK #1 len: 36 
Jul 21 09:27:54 ppp [opt2_link0] LCP: LayerUp 
Jul 21 09:27:54 ppp [opt2_link0] PAP: sending REQUEST #1 len: 31 
Jul 21 09:27:54 ppp [opt2_link0] PAP: using authname "user@streamyx" 
Jul 21 09:27:54 ppp [opt2_link0] LCP: auth: peer wants PAP, I want nothing 
Jul 21 09:27:54 ppp [opt2_link0] LCP: state change Ack-Rcvd --> Opened 
Jul 21 09:27:54 ppp [opt2_link0] MAGICNUM 0xc2f90d81 
Jul 21 09:27:54 ppp [opt2_link0] AUTHPROTO PAP 
Jul 21 09:27:54 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:54 ppp [opt2_link0] LCP: SendConfigAck #2 
Jul 21 09:27:54 ppp [opt2_link0] MAGICNUM 0xc2f90d81 
Jul 21 09:27:54 ppp [opt2_link0] AUTHPROTO PAP 
Jul 21 09:27:54 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:54 ppp [opt2_link0] LCP: rec'd Configure Request #2 (Ack-Rcvd) 
Jul 21 09:27:53 ppp [opt2_link0] LCP: state change Req-Sent --> Ack-Rcvd 
Jul 21 09:27:53 ppp [opt2_link0] MAGICNUM 0xc994d5bc 
Jul 21 09:27:53 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:53 ppp [opt2_link0] LCP: rec'd Configure Ack #3 (Req-Sent) 
Jul 21 09:27:53 ppp [opt2_link0] MAGICNUM 0xc994d5bc 
Jul 21 09:27:53 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:53 ppp [opt2_link0] LCP: SendConfigReq #3 
Jul 21 09:27:53 ppp [opt2_link0] LCP: state change Ack-Rcvd --> Req-Sent 
Jul 21 09:27:51 ppp [opt2_link0] LCP: state change Req-Sent --> Ack-Rcvd 
Jul 21 09:27:51 ppp [opt2_link0] MAGICNUM 0xc994d5bc 
Jul 21 09:27:51 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:51 ppp [opt2_link0] LCP: rec'd Configure Ack #2 (Req-Sent) 
Jul 21 09:27:51 ppp [opt2_link0] MAGICNUM 0xc994d5bc 
Jul 21 09:27:51 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:51 ppp [opt2_link0] LCP: SendConfigReq #2 
Jul 21 09:27:51 ppp [opt2_link0] PROTOCOMP 
Jul 21 09:27:51 ppp [opt2_link0] LCP: rec'd Configure Reject #1 (Req-Sent) 
Jul 21 09:27:51 ppp [opt2_link0] MAGICNUM 0xc994d5bc 
Jul 21 09:27:51 ppp [opt2_link0] MRU 1492 
Jul 21 09:27:51 ppp [opt2_link0] PROTOCOMP 
Jul 21 09:27:51 ppp [opt2_link0] LCP: SendConfigReq #1 
Jul 21 09:27:51 ppp [opt2_link0] LCP: state change Starting --> Req-Sent 
Jul 21 09:27:51 ppp [opt2_link0] LCP: Up event 
Jul 21 09:27:51 ppp [opt2_link0] Link: UP event 
Jul 21 09:27:51 ppp [opt2_link0] PPPoE: connection successful 
Jul 21 09:27:51 ppp PPPoE: rec'd ACNAME "BSRMC51" 
Jul 21 09:27:51 ppp [opt2_link0] PPPoE: Connecting to '' 
Jul 21 09:27:51 ppp [opt2_link0] LCP: LayerStart 
Jul 21 09:27:51 ppp [opt2_link0] LCP: state change Initial --> Starting 
Jul 21 09:27:51 ppp [opt2_link0] LCP: Open event 
Jul 21 09:27:51 ppp [opt2_link0] Link: OPEN event 
Jul 21 09:27:51 ppp [opt2] Bundle: Interface ng0 created 
Jul 21 09:27:51 ppp web: web is not running 
Jul 21 09:27:51 ppp process 78338 started, version 5.8 (root@pfSense_v2_3_2_amd64-pfSense_v2_3_2-job-04 16:03 19-Jul-2016) 
Jul 21 09:27:51 ppp Multi-link PPP daemon for FreeBSD 
Jul 21 09:27:49 ppp process 88099 terminated 
Jul 21 09:27:49 ppp [opt2_link0] Link: Shutdown 
Jul 21 09:27:49 ppp [opt2] Bundle: Shutdown 
Jul 21 09:27:47 ppp [opt2_link0] LCP: state change Closed --> Initial 
Jul 21 09:27:47 ppp [opt2_link0] LCP: Down event 
Jul 21 09:27:47 ppp [opt2_link0] Link: DOWN event 
Jul 21 09:27:47 ppp [opt2_link0] LCP: LayerFinish 
Jul 21 09:27:47 ppp [opt2_link0] LCP: state change Closing --> Closed 
Jul 21 09:27:47 ppp [opt2_link0] LCP: rec'd Terminate Ack #39 (Closing) 
Jul 21 09:27:47 ppp [opt2_link0] LCP: LayerDown 
Jul 21 09:27:47 ppp [opt2_link0] LCP: SendTerminateReq #39 
Jul 21 09:27:47 ppp [opt2] IPV6CP: state change Closed --> Initial 
Jul 21 09:27:47 ppp [opt2] IPV6CP: Down event 
Jul 21 09:27:47 ppp [opt2] IPCP: state change Closed --> Initial 
Jul 21 09:27:47 ppp [opt2] IPCP: Down event 
Jul 21 09:27:47 ppp [opt2] IPV6CP: Close event 
Jul 21 09:27:47 ppp [opt2] IPCP: Close event 
Jul 21 09:27:47 ppp [opt2] Bundle: Status update: up 0 links, total bandwidth 9600 bps 
Jul 21 09:27:47 ppp [opt2_link0] Link: Leave bundle "opt2" 
Jul 21 09:27:47 ppp [opt2_link0] LCP: state change Opened --> Closing 
Jul 21 09:27:47 ppp [opt2_link0] LCP: Close event 
Jul 21 09:27:47 ppp [opt2_link0] Link: CLOSE event 
Jul 21 09:27:47 ppp [opt2_link0] rec'd unexpected protocol IP 
Jul 21 09:27:47 ppp [opt2] Bundle: closing link "opt2_link0"... 
Jul 21 09:27:47 ppp [opt2] Bundle: No NCPs left. Closing links... 
Jul 21 09:27:47 ppp [opt2] IPV6CP: LayerFinish 
Jul 21 09:27:47 ppp [opt2] IPV6CP: state change Closing --> Closed 
Jul 21 09:27:47 ppp [opt2] IPV6CP: rec'd Terminate Ack #2 (Closing) 
Jul 21 09:27:47 ppp [opt2] IPCP: LayerFinish 
Jul 21 09:27:47 ppp [opt2] IPCP: state change Closing --> Closed 
Jul 21 09:27:47 ppp [opt2] IPCP: rec'd Terminate Ack #4 (Closing) 
Jul 21 09:27:47 ppp [opt2] IFACE: Rename interface pppoe0 to pppoe0 
Jul 21 09:27:47 ppp [opt2] IFACE: Down event 
Jul 21 09:27:46 ppp [opt2] IPV6CP: LayerDown 
Jul 21 09:27:46 ppp [opt2] IPV6CP: SendTerminateReq #2 
Jul 21 09:27:46 ppp [opt2] IPV6CP: state change Opened --> Closing 
Jul 21 09:27:46 ppp [opt2] IPV6CP: Close event 
Jul 21 09:27:46 ppp [opt2] IPCP: LayerDown 
Jul 21 09:27:46 ppp [opt2] IPCP: SendTerminateReq #4 
Jul 21 09:27:46 ppp [opt2] IPCP: state change Opened --> Closing 
Jul 21 09:27:46 ppp [opt2] IPCP: Close event 
Jul 21 09:27:46 ppp [opt2] IFACE: Close event 
Jul 21 09:27:46 ppp caught fatal signal TERM
    0
  • B

    Is you time correct?  I know a stupid question but it gets me every time.

    Randy

    0
  • J

    You mean the pfsense box itself time?

    Yes it is correct.

    0
  • P

    I’m having the same issue, quite disappointing.

    0
  • Netgate Administrator

    It was also working for you in 2.3.2? And failed at 2.3.4_1?

    Of not then what versions? What was happening and isn’t now?

    More info needed. 😉

    Steve

    0
    P
     1 Reply
  • P

    @stephenw10 This feature worked for me a long time ago (better part of a decade). After moving into area with crappy DSL I switched to cable where this feature is not needed. Now the DSL service in my neighborhood has been upgraded and I’m trying to switch away from cable.

    The ppp logs show the following:

    May 26 17:04:55 fw ppp: [opt1_link0] PPPoE: Connecting to ''
May 26 17:05:04 fw ppp: [opt1_link0] PPPoE connection timeout after 9 seconds
May 26 17:05:04 fw ppp: [opt1_link0] Link: DOWN event
May 26 17:05:04 fw ppp: [opt1_link0] LCP: Down event

    I’ve spent several hours reading forum posts and trying different settings, and that is about the best output I can get. tcpdump does indicate we are sending PADI:

    19:50:29.256594 PPPoE PADI [Host-Uniq 0x4051B3C8] [Service-Name]

    I’ve tried different transparent bridge settings on the modem as well, including creating a vlan 201, and configuring pppoe there, and running untagged directly on the interface.

    Setting pppoe back up on the modem results in a virtually immediate connection.

    I’m running this release because I’m on an old intel atom board. I’ve been running pfsense for over a decade and really don’t want to give it up… maybe I’ll just buy a SG-3100 and see if it works better for me on the latest version.

    *edit: oh, also, thank you very much for the reply.

    0
  • Netgate Administrator

    Ok, so you are actually running 2.3.4_1? You should update to 2.3.5_2 at least if your old Atom is old enough to be 32bit.

    I have run PPPoE on two DSL connections here through all the 2.3.X releases without issue. I suspect this is a difference with your DSL provider not a change in the PPPoE behaviour of pfSense.

    Who is you ISP? Many of them do require a VLAN as you said. Sometimes that is done in the modem.

    I’d be surprised if there are no references to using a 3rd party router with your provider even if that is not pfSense.

    Steve

    0
  • P

    Steve, thank you again very much for the replies!

    I did get this sorted, I’m with centurylink (thought @qwest.net domain), indeed it appears they do require a vlan 201 (on the modem). When I tried that previously it was with the wrong credentials/domain. It also appears that the tagging happens upstream, as it linked up without me tagging on pf (native/access port style).

    I am indeed running 2.3.4_1 as in system/update it says “Status : Up to date.” I’ll look into the version you’re recommending.

    0
  • Netgate Administrator

    There is an issue with 2.3.4 that prevents it seeing the updates. That was when we went to two branches and it can get confusing and start looking at 2.4.X where no 32bit updates exist.

    Try running the following command at the CLI or via Diag > Command Prompt:

    pkg-static clean -ya; pkg-static install -yf pkg pfSense-repo pfSense-upgrade

    That should force it to use the correct update package and see 2.3.5_2.

    Steve

    0
 

© Copyright 2002 - 2018 Rubicon Communications, LLC | Privacy Policy