PPPOE Not Working
-
Hi,
I am having no luck at all getting pfsense to connect to my ISP using PPPOE with modem in bridge mode. I know that the hardware works as i can install windows or any Linux on it and it connects just fine but when I install pfsense it will not connect no matter what I try. I do not want to use ipv6 at all. Below is the ppp log. I am wondering if PPPOE is somehow broken in pfsense? Has any one else had this problem? Anyone know how to fix this?
May 4 11:43:20 pfwall ppp: Multi-link PPP daemon for FreeBSD
May 4 11:43:20 pfwall ppp:
May 4 11:43:20 pfwall ppp: process 59632 started, version 5.7 (root@pfSense_RELENG_2_2_amd64_amd64-pfSense-job-02 10:17 19-Mar-2015)
May 4 11:43:20 pfwall ppp: waiting for process 6417 to die…
May 4 11:43:20 pfwall ppp: [wan] IFACE: Close event
May 4 11:43:20 pfwall ppp: [wan] IPCP: Close event
May 4 11:43:20 pfwall ppp: [wan] IPV6CP: Close event
May 4 11:43:21 pfwall ppp: waiting for process 6417 to die…
May 4 11:43:22 pfwall ppp: [wan] Bundle: Shutdown
May 4 11:43:22 pfwall ppp: waiting for process 6417 to die…
May 4 11:43:22 pfwall ppp: [wan_link0] Link: Shutdown
May 4 11:43:22 pfwall ppp: process 6417 terminated
May 4 11:43:23 pfwall ppp: web: web is not running
May 4 11:43:23 pfwall ppp: [wan] Bundle: Interface ng0 created
May 4 11:43:23 pfwall ppp: [wan_link0] Link: OPEN event
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: Open event
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Initial –> Starting
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: LayerStart
May 4 11:43:23 pfwall ppp: [wan_link0] PPPoE: Connecting to ''
May 4 11:43:23 pfwall ppp: PPPoE: rec'd ACNAME "qwbo-woolloongabba"
May 4 11:43:23 pfwall ppp: [wan_link0] PPPoE: connection successful
May 4 11:43:23 pfwall ppp: [wan_link0] Link: UP event
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: Up event
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Starting –> Req-Sent
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #1
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Request #19 (Req-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] AUTHPROTO CHAP MD5
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 02defa63
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigAck #19
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] AUTHPROTO CHAP MD5
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 02defa63
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: LayerUp
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: rec'd CHALLENGE #96 len: 39
May 4 11:43:23 pfwall ppp: [wan_link0] Name: "qwbo-woolloongabba"
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: Using authname "USER@qld.exetel.com.au"
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: sending RESPONSE #96 len: 49
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Request #1 (Opened)
May 4 11:43:23 pfwall ppp: [wan_link0] AUTHPROTO CHAP MD5
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 7c7ae9c1
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: LayerDown
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #2
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigAck #1
May 4 11:43:23 pfwall ppp: [wan_link0] AUTHPROTO CHAP MD5
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 7c7ae9c1
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Opened –> Ack-Sent
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Nak #2 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1500
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #3
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1500
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #4
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Nak #4 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1500
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #5
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Nak #5 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1500
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #6
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Nak #6 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1500
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #7
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Reject #7 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] MRU 1492
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: SendConfigReq #8
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: rec'd Configure Ack #8 (Ack-Sent)
May 4 11:43:23 pfwall ppp: [wan_link0] PROTOCOMP
May 4 11:43:23 pfwall ppp: [wan_link0] MAGICNUM 82e68810
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
May 4 11:43:23 pfwall ppp: [wan_link0] LCP: LayerUp
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: rec'd CHALLENGE #97 len: 35
May 4 11:43:23 pfwall ppp: [wan_link0] Name: "ESR04_WHAR_BNE"
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: Using authname "USER@qld.exetel.com.au"
May 4 11:43:23 pfwall ppp: [wan_link0] CHAP: sending RESPONSE #97 len: 49
May 4 11:43:24 pfwall ppp: [wan_link0] CHAP: rec'd SUCCESS #97 len: 4
May 4 11:43:24 pfwall ppp: [wan_link0] LCP: authorization successful
May 4 11:43:24 pfwall ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
May 4 11:43:24 pfwall ppp: [wan_link0] Link: Join bundle "wan"
May 4 11:43:24 pfwall ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
May 4 11:43:24 pfwall ppp: [wan] IPCP: Open event
May 4 11:43:24 pfwall ppp: [wan] IPCP: state change Initial –> Starting
May 4 11:43:24 pfwall ppp: [wan] IPCP: LayerStart
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: Open event
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: state change Initial –> Starting
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: LayerStart
May 4 11:43:24 pfwall ppp: [wan] IPCP: Up event
May 4 11:43:24 pfwall ppp: [wan] IPCP: state change Starting –> Req-Sent
May 4 11:43:24 pfwall ppp: [wan] IPCP: SendConfigReq #1
May 4 11:43:24 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:24 pfwall ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 4 11:43:24 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:24 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: Up event
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: state change Starting –> Req-Sent
May 4 11:43:24 pfwall ppp: [wan] IPV6CP: SendConfigReq #1
May 4 11:43:24 pfwall ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
May 4 11:43:24 pfwall ppp: [wan] IPADDR 58.96..
May 4 11:43:24 pfwall ppp: [wan] 58.96.. is OK
May 4 11:43:24 pfwall ppp: [wan] IPCP: SendConfigAck #1
May 4 11:43:24 pfwall ppp: [wan] IPADDR 58.96..
May 4 11:43:24 pfwall ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
May 4 11:43:24 pfwall ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
May 4 11:43:24 pfwall ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
May 4 11:43:24 pfwall ppp: [wan] IPCP: SendConfigReq #2
May 4 11:43:24 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:24 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:24 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:26 pfwall ppp: [wan] IPV6CP: SendConfigReq #2
May 4 11:43:26 pfwall ppp: [wan] IPCP: SendConfigReq #3
May 4 11:43:26 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:26 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:26 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:28 pfwall ppp: [wan] IPV6CP: SendConfigReq #3
May 4 11:43:28 pfwall ppp: [wan] IPCP: SendConfigReq #4
May 4 11:43:28 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:28 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:28 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:30 pfwall ppp: [wan] IPV6CP: SendConfigReq #4
May 4 11:43:30 pfwall ppp: [wan] IPCP: SendConfigReq #5
May 4 11:43:30 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:30 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:30 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:32 pfwall ppp: [wan] IPCP: SendConfigReq #6
May 4 11:43:32 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:32 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:32 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:32 pfwall ppp: [wan] IPV6CP: SendConfigReq #5
May 4 11:43:34 pfwall ppp: [wan] IPV6CP: SendConfigReq #6
May 4 11:43:34 pfwall ppp: [wan] IPCP: SendConfigReq #7
May 4 11:43:34 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:34 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:34 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:36 pfwall ppp: [wan] IPCP: SendConfigReq #8
May 4 11:43:36 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:36 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:36 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:36 pfwall ppp: [wan] IPV6CP: SendConfigReq #7
May 4 11:43:38 pfwall ppp: [wan] IPV6CP: SendConfigReq #8
May 4 11:43:38 pfwall ppp: [wan] IPCP: SendConfigReq #9
May 4 11:43:38 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:38 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:38 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:40 pfwall ppp: [wan] IPCP: SendConfigReq #10
May 4 11:43:40 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:40 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:40 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:40 pfwall ppp: [wan] IPV6CP: SendConfigReq #9
May 4 11:43:42 pfwall ppp: [wan] IPV6CP: SendConfigReq #10
May 4 11:43:42 pfwall ppp: [wan] IPCP: SendConfigReq #11
May 4 11:43:42 pfwall ppp: [wan] IPADDR 0.0.0.0
May 4 11:43:42 pfwall ppp: [wan] PRIDNS 0.0.0.0
May 4 11:43:42 pfwall ppp: [wan] SECDNS 0.0.0.0
May 4 11:43:44 pfwall ppp: [wan] IPCP: parameter negotiation failed
May 4 11:43:44 pfwall ppp: [wan] IPCP: state change Ack-Sent –> Stopped
May 4 11:43:44 pfwall ppp: [wan] IPCP: LayerFinish
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: parameter negotiation failed
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: state change Req-Sent –> Stopped
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: LayerFinish
May 4 11:43:44 pfwall ppp: [wan] Bundle: No NCPs left. Closing links…
May 4 11:43:44 pfwall ppp: [wan] Bundle: closing link "wan_link0"…
May 4 11:43:44 pfwall ppp: [wan_link0] Link: CLOSE event
May 4 11:43:44 pfwall ppp: [wan_link0] LCP: Close event
May 4 11:43:44 pfwall ppp: [wan_link0] LCP: state change Opened –> Closing
May 4 11:43:44 pfwall ppp: [wan_link0] Link: Leave bundle "wan"
May 4 11:43:44 pfwall ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
May 4 11:43:44 pfwall ppp: [wan] IPCP: Close event
May 4 11:43:44 pfwall ppp: [wan] IPCP: state change Stopped –> Closed
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: Close event
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: state change Stopped –> Closed
May 4 11:43:44 pfwall ppp: [wan] IPCP: Down event
May 4 11:43:44 pfwall ppp: [wan] IPCP: state change Closed –> Initial
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: Down event
May 4 11:43:44 pfwall ppp: [wan] IPV6CP: state change Closed –> Initial
May 4 11:43:44 pfwall ppp: [wan_link0] LCP: SendTerminateReq #9
May 4 11:43:44 pfwall ppp: [wan_link0] LCP: LayerDown
May 4 11:43:46 pfwall ppp: [wan_link0] LCP: SendTerminateReq #10
May 4 11:43:46 pfwall ppp: [wan_link0] rec'd proto IPCP during terminate phase
May 4 11:43:48 pfwall ppp: [wan_link0] LCP: state change Closing –> Closed
May 4 11:43:48 pfwall ppp: [wan_link0] LCP: LayerFinish
May 4 11:43:48 pfwall ppp: [wan_link0] Link: DOWN event
May 4 11:43:48 pfwall ppp: [wan_link0] LCP: Down event
May 4 11:43:48 pfwall ppp: [wan_link0] LCP: state change Closed –> Initial -
I'm so glad I did a search today for this. I have spent a good part of my weekend trying to understand this problem. Funny enough, I'm with Exetel too in Queensland and can confirm this is a problem for myself and several other long time PfSense users. This issue first appeared around December 2014 and has been a constant issue since.
Here's what I know so far:-
- Affects the latest version of PfSense 2.2.2.
- Is not actually related to IPv6 negotiation - I copied the mpd_wan.conf across to /conf and manually edited the file to disable IPv6. I can see through Wireshark that the IPv6 negotiation never occurs but the problem persists.
- Seems to be specific to mpd5. I have consistent PPPoE connectivity with ClearOS which doesn't use mpd5.
- After several failed connection attempts, it looks like Exetel are filtering the connection attempts. You have to back off from trying to connect otherwise Exetel will continue to block for an extended period of time (I've had it block me for 24 hours)
- More technically, Exetel stops responding with PADO packets to the PADI packet sent by PfSense. If I switch MAC addresses, the PADO responses return indicating MAC address level filtering for an unknown period of time.
For me the biggest thing here is that ClearOS works perfectly, every connection attempt succeeds.
I originally had a small Intel PC which ran my PfSense box. For the weekend's testing I switched to a Hyper-V based Virtual Machine so that I could use Wireshark on the host to monitor the PfSense connections.
I've captured the following scenarios:-
- Successful ClearOS connection
- Successful PfSense connection (yes it does work very occasionally)
- Failed PfSense connection
Comparing the wireshark captures there are three areas that stand out to me:
1. mpd5 wants to negotiate for an MRU of 1492, Exetel responds with a Nak to this configuration request instead requesting a MRU of 1500. mpd5 doesn't support configuring an MRU of 1500 for PPPoE.
2. ClearOS actually experiences the same MRU 1492 configuration request and corresponding NAK. Now the difference here is that ClearOS simply ignores the NAK response and moves onto the rest of the CHAP authentication and configuration process eventually arriving at a configuration ACK and the connection is established.
3. PfSense on the other hand receives the NAK for the MRU and retries the MRU configuration multiple times (6 in total). On the sixth attempt, Exetel responds with a REJ to the MRU configuration. Whilst the connection process continues at this point, I think this might be what causes the problem.
- When PfSense reaches the PPP IPCP stage, it attempts to resolve the WAN IP address to use. It sends this IP address to Exetel in a Configuration request but Exetel never responds to the request with an ACK response. This is the key difference between ClearOS and PfSense. ClearOS consistently receives a configuration ACK from Exetel.If anyone would like to review the Wireshark logs in more detail. I can strip out the user specific stuff and provide them on a per request basis.
I really hope we can get this sorted - Exetel have seemed very unwilling to help with testing from their end but since finding that ClearOS works so consistently, I'm hoping a resolution can be reached without them. -
Well that a real pity. I was so looking forward to using pfsense. Looks like I will have to keep using SOPHOS until this gets sorted.
-
I've been having issues with PPPoE as well…..
-
This seems to be fixed now. Has been connecting every time over the past few days. I assume that it was fixed on the ISP end?
-
Glad to hear its working better, I've been liaising with Exetel to work through these fixes since late last week.
I still see a heartbeat problem which means the connection drops more frequently than it should but at least it reconnects automatically.
Would you mind checking your logs and seeing if you can identify how frequently your connection drops and reconnects?