MLPPP not working - Multilink is not Negociated by MPD5 - PPPOE Changes

jacobhuh

BTW, there are other users with this problem using the latest iteration of PFSENSE for MLPPP. That is on my side of the fence up here in Western Canada.

jacobhuh

If you look at when MPD5 is called to Bundle the links together the second line is rejected as there is an error stating that the second "link did not validate in bundle". The logs are not verbose enough to find out what part of the link did not validate? Authentication looks fine, MTU/MRRU/MRU doesn't show issues, could it be that the second connection is trying to bond too early as IP Address has not negociated with the First link yet? Anyways, after the IP Address negotiates and resolves every subsequent retry is denied with a Message of "MESG: duplicate address detected". Another administrator indicates that it is PFSENSE that is throwing the messages and rejects the link?

Anyone have any suggestions or know who's door I can knock on? My only other option is the run the Mikrotik to resolve the MLPPP VDSL connection and then setup a 1:1 NAT so that I can still use PFSENSE as the serverside router to my internal network. I've been told for the most part OpenVPN will not have a problem (I run a Server with four clients for a distributed LAN).

Jacob

doktornotor

While you are messing with configuration in shell in unknown ways, you really won't get any meaningful support here. As already noted, it will get overwritten plus is completely undesired.

cmb

@doktornotor:

While you are messing with configuration in shell in unknown ways, you really won't get any meaningful support here.

That was the point I was trying to get at earlier. Right now this is more a "please debug my custom mpd.conf", which isn't going to get much attention.

Go back to what the system generates on its own, and post your PPP logs. That I'm happy to help with.

chpalmer

I have a site connected via MLPPP running the latest snaps and things are fine. Nothing custom needed.

jacobhuh

It was essentially a copy of the auto generated one. I will post the auto generated one, but same result in the logs. How can one get verbose logs utilizing the auto generated config, we will start there.

jacobhuh

Alright here is the log from the PFSENSE 2.2.5 (Snapshot from updating yesterday), running on a standard MLPPP PPPOE setup with two VDSL 50/10 links (Zyxel Modems setup in Bridge). The modems are setup on two adapters EM1 and EM2 which are setup in the Interface Page under the Tab in a PPPs and assigned the identifier PPPOE0(em1, em2). WAN is assigned the PPPOE0 and all the necessary details are setup. (I can provide screenshots if needed). The error is the same. Does anyone have a clue as to what could be the issue?

Again it works with other MLPPP routers such as the Mikrotik 750, but I really really do not want to use it.

Sep 29 22:51:56 imperialhome ppp: Multi-link PPP daemon for FreeBSD
Sep 29 22:51:56 imperialhome ppp:
Sep 29 22:51:56 imperialhome ppp: process 57962 started, version 5.7 (root@pfSense_RELENG_2_2_amd64_amd64-pfSense_RELENG_2_2-job-01 00:07 9-Jun-2015)
Sep 29 22:51:56 imperialhome ppp: web: web is not running
Sep 29 22:51:56 imperialhome ppp: [wan] Bundle: Interface ng0 created
Sep 29 22:51:56 imperialhome ppp: [wan_link0] Link: OPEN event
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: Open event
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: state change Initial –> Starting
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: LayerStart
Sep 29 22:51:56 imperialhome ppp: [wan_link1] Link: OPEN event
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: Open event
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: state change Initial –> Starting
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: LayerStart
Sep 29 22:51:56 imperialhome ppp: [wan_link0] PPPoE: Connecting to 'Teksavvy'
Sep 29 22:51:56 imperialhome ppp: [wan_link1] PPPoE: Connecting to 'Teksavvy'
Sep 29 22:51:56 imperialhome ppp: PPPoE: rec'd ACNAME "CLGRAB21AR04"
Sep 29 22:51:56 imperialhome ppp: PPPoE: rec'd ACNAME "CLGRAB21AR04"
Sep 29 22:51:56 imperialhome ppp: [wan_link0] PPPoE: connection successful
Sep 29 22:51:56 imperialhome ppp: [wan_link0] Link: UP event
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: Up event
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: state change Starting –> Req-Sent
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: SendConfigReq #1
Sep 29 22:51:56 imperialhome ppp: [wan_link0] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MAGICNUM b54bbafa
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link0] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:51:56 imperialhome ppp: [wan_link1] PPPoE: connection successful
Sep 29 22:51:56 imperialhome ppp: [wan_link1] Link: UP event
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: Up event
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: state change Starting –> Req-Sent
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: SendConfigReq #1
Sep 29 22:51:56 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MAGICNUM b88404e2
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: rec'd Configure Request #245 (Req-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MRU 1460
Sep 29 22:51:56 imperialhome ppp: [wan_link0] AUTHPROTO CHAP MD5
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MAGICNUM 4c75d946
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: SendConfigAck #245
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MRU 1460
Sep 29 22:51:56 imperialhome ppp: [wan_link0] AUTHPROTO CHAP MD5
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MAGICNUM 4c75d946
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link0] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: SendConfigReq #2
Sep 29 22:51:56 imperialhome ppp: [wan_link0] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MAGICNUM b54bbafa
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: rec'd Configure Request #105 (Req-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MRU 1460
Sep 29 22:51:56 imperialhome ppp: [wan_link1] AUTHPROTO CHAP MD5
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MAGICNUM 34423367
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: SendConfigAck #105
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MRU 1460
Sep 29 22:51:56 imperialhome ppp: [wan_link1] AUTHPROTO CHAP MD5
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MAGICNUM 34423367
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: state change Req-Sent –> Ack-Sent
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: SendConfigReq #2
Sep 29 22:51:56 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MAGICNUM b88404e2
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link0] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MAGICNUM b54bbafa
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: LayerUp
Sep 29 22:51:56 imperialhome ppp: [wan_link0] CHAP: rec'd CHALLENGE #84 len: 37
Sep 29 22:51:56 imperialhome ppp: [wan_link0] Name: "CLGRAB21AR04"
Sep 29 22:51:56 imperialhome ppp: [wan_link0] CHAP: Using authname "xxxxxxxx@wiredhighspeed.com"
Sep 29 22:51:56 imperialhome ppp: [wan_link0] CHAP: sending RESPONSE #84 len: 48
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: rec'd Configure Ack #2 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MAGICNUM b88404e2
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: state change Ack-Sent –> Opened
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: auth: peer wants CHAP, I want nothing
Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: LayerUp
Sep 29 22:51:56 imperialhome ppp: [wan_link1] CHAP: rec'd CHALLENGE #244 len: 40
Sep 29 22:51:56 imperialhome ppp: [wan_link1] Name: "CLGRAB21AR04"
Sep 29 22:51:56 imperialhome ppp: [wan_link1] CHAP: Using authname "xxxxxxxx@wiredhighspeed.com"
Sep 29 22:51:56 imperialhome ppp: [wan_link1] CHAP: sending RESPONSE #244 len: 48
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: rec'd Configure Request #230 (Opened)
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MRU 1452
Sep 29 22:51:57 imperialhome ppp: [wan_link0] AUTHPROTO PAP
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MAGICNUM 4e76549f
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: LayerDown
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: SendConfigReq #3
Sep 29 22:51:57 imperialhome ppp: [wan_link0] PROTOCOMP
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MRU 1492
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MAGICNUM b54bbafa
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: SendConfigAck #230
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MRU 1452
Sep 29 22:51:57 imperialhome ppp: [wan_link0] AUTHPROTO PAP
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MAGICNUM 4e76549f
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: state change Opened –> Ack-Sent
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: rec'd Configure Request #180 (Opened)
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MRU 1452
Sep 29 22:51:57 imperialhome ppp: [wan_link1] AUTHPROTO PAP
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MAGICNUM 2d1d6c80
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: LayerDown
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: SendConfigReq #3
Sep 29 22:51:57 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MAGICNUM b88404e2
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: SendConfigAck #180
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MRU 1452
Sep 29 22:51:57 imperialhome ppp: [wan_link1] AUTHPROTO PAP
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MAGICNUM 2d1d6c80
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: state change Opened –> Ack-Sent
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: rec'd Configure Ack #3 (Ack-Sent)
Sep 29 22:51:57 imperialhome ppp: [wan_link0] PROTOCOMP
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MRU 1492
Sep 29 22:51:57 imperialhome ppp: [wan_link0] MAGICNUM b54bbafa
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
Sep 29 22:51:57 imperialhome ppp: [wan_link0] PAP: using authname "xxxxxxxx@wiredhighspeed.com"
Sep 29 22:51:57 imperialhome ppp: [wan_link0] PAP: sending REQUEST #1 len: 43
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: LayerUp
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: rec'd Configure Ack #3 (Ack-Sent)
Sep 29 22:51:57 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:51:57 imperialhome ppp: [wan_link1] MAGICNUM b88404e2
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: state change Ack-Sent –> Opened
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: auth: peer wants PAP, I want nothing
Sep 29 22:51:57 imperialhome ppp: [wan_link1] PAP: using authname "xxxxxxxx@wiredhighspeed.com"
Sep 29 22:51:57 imperialhome ppp: [wan_link1] PAP: sending REQUEST #1 len: 43
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: LayerUp
Sep 29 22:51:57 imperialhome ppp: [wan_link0] PAP: rec'd ACK #1 len: 5
Sep 29 22:51:57 imperialhome ppp: [wan_link0] LCP: authorization successful
Sep 29 22:51:57 imperialhome ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
Sep 29 22:51:57 imperialhome ppp: [wan_link0] Link: Join bundle "wan"
Sep 29 22:51:57 imperialhome ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: Open event
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: state change Initial –> Starting
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: LayerStart
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: Open event
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: state change Initial –> Starting
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: LayerStart
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: Up event
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: state change Starting –> Req-Sent
Sep 29 22:51:57 imperialhome ppp: [wan] IPCP: SendConfigReq #1
Sep 29 22:51:57 imperialhome ppp: [wan] IPADDR 0.0.0.0
Sep 29 22:51:57 imperialhome ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Sep 29 22:51:57 imperialhome ppp: [wan] PRIDNS 0.0.0.0
Sep 29 22:51:57 imperialhome ppp: [wan] SECDNS 0.0.0.0
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: Up event
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: state change Starting –> Req-Sent
Sep 29 22:51:57 imperialhome ppp: [wan] IPV6CP: SendConfigReq #1
Sep 29 22:51:57 imperialhome ppp: [wan_link1] PAP: rec'd ACK #1 len: 5
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: authorization successful
Sep 29 22:51:57 imperialhome ppp: [wan_link1] Link: Matched action 'bundle "wan" ""'
Sep 29 22:51:57 imperialhome ppp: [wan_link1] Can't join bundle wan without multilink negotiated.
Sep 29 22:51:57 imperialhome ppp: [wan_link1] link did not validate in bundle
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: parameter negotiation failed
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: state change Opened –> Stopping
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: SendTerminateReq #4
Sep 29 22:51:57 imperialhome ppp: [wan_link1] LCP: LayerDown
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: rec'd Terminate Ack #4 (Stopping)
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: state change Stopping –> Stopped
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: LayerFinish
Sep 29 22:51:58 imperialhome ppp: [wan_link1] PPPoE: connection closed
Sep 29 22:51:58 imperialhome ppp: [wan_link1] Link: DOWN event
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: Down event
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: state change Stopped –> Starting
Sep 29 22:51:58 imperialhome ppp: [wan_link1] LCP: LayerStart
Sep 29 22:51:58 imperialhome ppp: [wan_link1] Link: reconnection attempt 1 in 1 seconds
Sep 29 22:51:58 imperialhome ppp: [wan] IPCP: rec'd Configure Request #166 (Req-Sent)
Sep 29 22:51:58 imperialhome ppp: [wan] IPADDR 76.10.191.6
Sep 29 22:51:58 imperialhome ppp: [wan] 76.10.191.6 is OK
Sep 29 22:51:58 imperialhome ppp: [wan] IPCP: SendConfigAck #166
Sep 29 22:51:58 imperialhome ppp: [wan] IPADDR 76.10.191.6
Sep 29 22:51:58 imperialhome ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
Sep 29 22:51:58 imperialhome ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 29 22:51:58 imperialhome ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Sep 29 22:51:58 imperialhome ppp: [wan] IPCP: SendConfigReq #2
Sep 29 22:51:58 imperialhome ppp: [wan] IPADDR 0.0.0.0
Sep 29 22:51:58 imperialhome ppp: [wan] PRIDNS 0.0.0.0
Sep 29 22:51:58 imperialhome ppp: [wan] SECDNS 0.0.0.0
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: rec'd Configure Request #199 (Req-Sent)
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: SendConfigAck #199
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: state change Req-Sent –> Ack-Sent
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: rec'd Configure Ack #1 (Ack-Sent)
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: state change Ack-Sent –> Opened
Sep 29 22:51:58 imperialhome ppp: [wan] IPV6CP: LayerUp
Sep 29 22:51:58 imperialhome ppp: [wan] 0230:18ff:fea3:b13f -> 0090:1a00:0343:14ab
Sep 29 22:51:59 imperialhome ppp: [wan] IFACE: Up event
Sep 29 22:51:59 imperialhome ppp: [wan] IFACE: Rename interface ng0 to pppoe0
Sep 29 22:51:59 imperialhome ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Sep 29 22:51:59 imperialhome ppp: [wan] IPADDR 76.10.188.94
Sep 29 22:51:59 imperialhome ppp: [wan] 76.10.188.94 is OK
Sep 29 22:51:59 imperialhome ppp: [wan] PRIDNS 76.10.191.198
Sep 29 22:51:59 imperialhome ppp: [wan] SECDNS 76.10.191.199
Sep 29 22:51:59 imperialhome ppp: [wan] IPCP: SendConfigReq #3
Sep 29 22:51:59 imperialhome ppp: [wan] IPADDR 76.10.188.94
Sep 29 22:51:59 imperialhome ppp: [wan] PRIDNS 76.10.191.198
Sep 29 22:51:59 imperialhome ppp: [wan] SECDNS 76.10.191.199
Sep 29 22:51:59 imperialhome ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Sep 29 22:51:59 imperialhome ppp: [wan] IPADDR 76.10.188.94
Sep 29 22:51:59 imperialhome ppp: [wan] PRIDNS 76.10.191.198
Sep 29 22:51:59 imperialhome ppp: [wan] SECDNS 76.10.191.199
Sep 29 22:51:59 imperialhome ppp: [wan] IPCP: state change Ack-Sent –> Opened
Sep 29 22:51:59 imperialhome ppp: [wan] IPCP: LayerUp
Sep 29 22:51:59 imperialhome ppp: [wan] 76.10.188.94 -> 76.10.191.6
Sep 29 22:52:00 imperialhome ppp: [wan_link1] Link: reconnection attempt 1
Sep 29 22:52:00 imperialhome ppp: [wan_link1] PPPoE: Connecting to 'Teksavvy'
Sep 29 22:52:00 imperialhome ppp: PPPoE: rec'd ACNAME "CLGRAB21AR04"
Sep 29 22:52:01 imperialhome ppp: [wan_link1] PPPoE: connection successful
Sep 29 22:52:01 imperialhome ppp: [wan_link1] Link: UP event
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: Up event
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: state change Starting –> Req-Sent
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: SendConfigReq #5
Sep 29 22:52:01 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MAGICNUM 8e771b44
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:52:01 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: rec'd Configure Request #148 (Req-Sent)
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MRU 1460
Sep 29 22:52:01 imperialhome ppp: [wan_link1] AUTHPROTO CHAP MD5
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MAGICNUM 30f53071
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: SendConfigAck #148
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MRU 1460
Sep 29 22:52:01 imperialhome ppp: [wan_link1] AUTHPROTO CHAP MD5
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MAGICNUM 30f53071
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: state change Req-Sent –> Ack-Sent
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: rec'd Configure Reject #5 (Ack-Sent)
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:52:01 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: SendConfigReq #6
Sep 29 22:52:01 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MAGICNUM 8e771b44
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: rec'd Configure Ack #6 (Ack-Sent)
Sep 29 22:52:01 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MAGICNUM 8e771b44
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: state change Ack-Sent –> Opened
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: auth: peer wants CHAP, I want nothing
Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: LayerUp
Sep 29 22:52:01 imperialhome ppp: [wan_link1] CHAP: rec'd CHALLENGE #114 len: 34
Sep 29 22:52:01 imperialhome ppp: [wan_link1] Name: "CLGRAB21AR04"
Sep 29 22:52:01 imperialhome ppp: [wan_link1] CHAP: Using authname "xxxxxxx@wiredhighspeed.com"
Sep 29 22:52:01 imperialhome ppp: [wan_link1] CHAP: sending RESPONSE #114 len: 48
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: rec'd Configure Request #228 (Opened)
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MRU 1452
Sep 29 22:52:02 imperialhome ppp: [wan_link1] AUTHPROTO PAP
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MAGICNUM 76e3c276
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: LayerDown
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: SendConfigReq #7
Sep 29 22:52:02 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MAGICNUM 8e771b44
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: SendConfigAck #228
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MRU 1452
Sep 29 22:52:02 imperialhome ppp: [wan_link1] AUTHPROTO PAP
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MAGICNUM 76e3c276
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: state change Opened –> Ack-Sent
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: rec'd Configure Ack #7 (Ack-Sent)
Sep 29 22:52:02 imperialhome ppp: [wan_link1] PROTOCOMP
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MRU 1492
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MAGICNUM 8e771b44
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: state change Ack-Sent –> Opened
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: auth: peer wants PAP, I want nothing
Sep 29 22:52:02 imperialhome ppp: [wan_link1] PAP: using authname "xxxxxxxx@wiredhighspeed.com"
Sep 29 22:52:02 imperialhome ppp: [wan_link1] PAP: sending REQUEST #1 len: 43
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: LayerUp
Sep 29 22:52:02 imperialhome ppp: [wan_link1] PAP: rec'd NAK #1 len: 31
Sep 29 22:52:02 imperialhome ppp: [wan_link1] MESG: duplicate address detected
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: authorization failed
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: parameter negotiation failed
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: state change Opened –> Stopping
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: SendTerminateReq #8
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: LayerDown
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: rec'd Terminate Request #141 (Stopping)
Sep 29 22:52:02 imperialhome ppp: [wan_link1] LCP: SendTerminateAck #9
Sep 29 22:52:03 imperialhome ppp: [wan_link1] PPPoE: connection closed
Sep 29 22:52:03 imperialhome ppp: [wan_link1] Link: DOWN event
Sep 29 22:52:03 imperialhome ppp: [wan_link1] LCP: Down event
Sep 29 22:52:03 imperialhome ppp: [wan_link1] LCP: state change Stopping –> Starting
Sep 29 22:52:03 imperialhome ppp: [wan_link1] Link: reconnection attempt 2 in 4 seconds

chpalmer

Had you run into this thread- https://forum.pfsense.org/index.php?topic=36966.0 ??

jacobhuh

Yeah,
If you refer to one of the member "Clarknova" he's local here to me and he has had the same problem!! He posted to our ISP's forum and same thing they are blaming PFSENSE for having the issue.

Jacob

jacobhuh

Has anyone else seen this same? There is something definitely wrong with PFSense or MPD5. My MLPPP connection works with a Mikrotik 750, but is a no go with PFSENSE (both Stable and Current)

Jacob

chpalmer

My MLPPP connection works fine.

Olypen in Washington State.

David_W

@jacobhuh:

<snip>Sep 29 22:51:56 imperialhome ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link0] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link0] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f

<snip more="">Sep 29 22:51:56 imperialhome ppp: [wan_link1] LCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:51:56 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:51:56 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f

<snip more="">Sep 29 22:52:01 imperialhome ppp: [wan_link1] LCP: rec'd Configure Reject #5 (Ack-Sent)
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP MRRU 1486
Sep 29 22:52:01 imperialhome ppp: [wan_link1] MP SHORTSEQ
Sep 29 22:52:01 imperialhome ppp: [wan_link1] ENDPOINTDISC [802.1] 00 30 18 a3 b1 3f</snip></snip></snip>

The remote end rejects the multilink parameters on both links, so multilink has not been negotiated and the two links cannot be joined.

In 'Advanced Options' check 'Disable shortseq'. Does it work now?

jacobhuh

No unfortunately not at all. Same problem.

David_W

As disabling shortseq hasn't solved the problem, I'd try a lower MRRU (you need to press the 'Advanced Options' button for that setting). The remote end is requesting an MRU of 1460, so I'd start by trying an MRRU of 1454 (which allows for the 6 byte multilink overhead). If that doesn't work, try an even lower MRRU - maybe try 1400.

If you find a working MRRU, start increasing MRRU until it fails, then use the highest setting that works. At that point, re-enable shortseq and see if things continue to work.

This is likely to involve finding working settings by trial and error unless you can get any hints from the ISP or from the logs of a system that successfully negotiates multilink with your ISP.