2.0RC MLPPP doesn't work with my provider

Epoch

Found more things to log, I will give that a try later and see if anything else shows up in the logs. I apologize for being a little slow, I should have seen the asterisk on those manual pages and figured out that there were additional debugging logs to turn on for LCP logging.
More results later, hopefully with relevant details.

Epoch

I enabled logging for BUND, BUND2, AUTH, AUTH2, LCP, LCP2, CCP, CCP2, ECP, ECP2, ECHO, and the other defaults and came up with the following in my logs. It really does look like mpd5 is getting the configuration request sent by my ISP's LNS and completely ignoring it.

ppp: Multi-link PPP daemon for FreeBSD
ppp:  
ppp: process 8179 started, version 5.5 (root@FreeBSD_8.0_pfSense_2.0-snaps.pfsense.org 13:37 25-May-2011)
ppp: web: web is not running
ppp: [wan] Bundle: Interface ng0 created
ppp: [wan_link0] Link: OPEN event
ppp: [wan_link0] LCP: Open event
ppp: [wan_link0] LCP: state change Initial --> Starting
ppp: [wan_link0] LCP: LayerStart
ppp: [wan_link1] Link: OPEN event
ppp: [wan_link1] LCP: Open event
ppp: [wan_link1] LCP: state change Initial --> Starting
ppp: [wan_link1] LCP: LayerStart
ppp: [wan_link0] PPPoE: Connecting to ''
ppp: [wan_link1] PPPoE: Connecting to ''
ppp: PPPoE: rec'd ACNAME "lns3-WNDSON17"
ppp: PPPoE: rec'd ACNAME "lns3-WNDSON17"
ppp: [wan_link1] PPPoE: connection successful
ppp: [wan_link1] Link: UP event
ppp: [wan_link1] LCP: Up event
ppp: [wan_link1] LCP: state change Starting --> Req-Sent
ppp: [wan_link1] LCP: phase shift DEAD --> ESTABLISH
ppp: [wan_link1] LCP: SendConfigReq #1
ppp: [wan_link1]   PROTOCOMP
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   MAGICNUM 27336dd6
ppp: [wan_link1]   MP MRRU 1524
ppp: [wan_link1]   MP SHORTSEQ
ppp: [wan_link1]   ENDPOINTDISC [802.1] 00 30 48 db 09 36
ppp: [wan_link0] PPPoE: connection successful
ppp: [wan_link0] Link: UP event
ppp: [wan_link0] LCP: Up event
ppp: [wan_link0] LCP: state change Starting --> Req-Sent
ppp: [wan_link0] LCP: phase shift DEAD --> ESTABLISH
ppp: [wan_link0] LCP: SendConfigReq #1
ppp: [wan_link0]   PROTOCOMP
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   MAGICNUM 2458176a
ppp: [wan_link0]   MP MRRU 1524
ppp: [wan_link0]   MP SHORTSEQ
ppp: [wan_link0]   ENDPOINTDISC [802.1] 00 30 48 db 09 36
ppp: [wan_link1] LCP: rec'd Configure Request #1 (Req-Sent)
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   AUTHPROTO PAP
ppp: [wan_link1]   MAGICNUM be84fab0
ppp: [wan_link1] LCP: SendConfigAck #1
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   AUTHPROTO PAP
ppp: [wan_link1]   MAGICNUM be84fab0
ppp: [wan_link1] LCP: state change Req-Sent --> Ack-Sent
ppp: [wan_link1] LCP: rec'd Configure Reject #1 (Ack-Sent)
ppp: [wan_link1]   MP MRRU 1524
ppp: [wan_link1]   MP SHORTSEQ
ppp: [wan_link1] LCP: SendConfigReq #2
ppp: [wan_link1]   PROTOCOMP
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   MAGICNUM 27336dd6
ppp: [wan_link0] LCP: rec'd Configure Request #1 (Req-Sent)
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   AUTHPROTO PAP
ppp: [wan_link0]   MAGICNUM be84fabd
ppp: [wan_link0] LCP: SendConfigAck #1
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   AUTHPROTO PAP
ppp: [wan_link0]   MAGICNUM be84fabd
ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
ppp: [wan_link0]   MP MRRU 1524
ppp: [wan_link0]   MP SHORTSEQ
ppp: [wan_link0] LCP: SendConfigReq #2
ppp: [wan_link0]   PROTOCOMP
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   MAGICNUM 2458176a
ppp: [wan_link1] LCP: rec'd Configure Ack #2 (Ack-Sent)
ppp: [wan_link1]   PROTOCOMP
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   MAGICNUM 27336dd6
ppp: [wan_link1] LCP: state change Ack-Sent --> Opened
ppp: [wan_link1] LCP: phase shift ESTABLISH --> AUTHENTICATE
ppp: [wan_link1] LCP: auth: peer wants PAP, I want nothing
ppp: [wan_link1] PAP: using authname "mppp%user@mnsi.net"
ppp: [wan_link1] PAP: sending REQUEST #1 len: 36
ppp: [wan_link1] LCP: LayerUp
ppp: [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
ppp: [wan_link0]   PROTOCOMP
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   MAGICNUM 2458176a
ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
ppp: [wan_link0] LCP: phase shift ESTABLISH --> AUTHENTICATE
ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
ppp: [wan_link0] PAP: using authname "mppp%user@mnsi.net"
ppp: [wan_link0] PAP: sending REQUEST #1 len: 36
ppp: [wan_link0] LCP: LayerUp
ppp: [wan_link1] LCP: rec'd Configure Request #1 (Opened)
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   AUTHPROTO PAP
ppp: [wan_link1]   MAGICNUM c0c2405b
ppp: [wan_link1]   MP MRRU 1524
ppp: [wan_link1]   ENDPOINTDISC [LOCAL] 6c 6e 73 34 2d 57 4e 44 53 4f 4e 31 37
ppp: [wan_link1] LCP: LayerDown
ppp: [wan_link1] LCP: SendConfigReq #3
ppp: [wan_link1]   PROTOCOMP
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   MAGICNUM 27336dd6
ppp: [wan_link1] LCP: SendConfigAck #1
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   AUTHPROTO PAP
ppp: [wan_link1]   MAGICNUM c0c2405b
ppp: [wan_link1]   MP MRRU 1524
ppp: [wan_link1]   ENDPOINTDISC [LOCAL] 6c 6e 73 34 2d 57 4e 44 53 4f 4e 31 37
ppp: [wan_link1] LCP: state change Opened --> Ack-Sent
ppp: [wan_link1] LCP: phase shift AUTHENTICATE --> ESTABLISH
ppp: [wan_link1] AUTH: Cleanup
ppp: [wan_link0] LCP: rec'd Configure Request #1 (Opened)
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   AUTHPROTO PAP
ppp: [wan_link0]   MAGICNUM c0c24075
ppp: [wan_link0]   MP MRRU 1524
ppp: [wan_link0]   ENDPOINTDISC [LOCAL] 6c 6e 73 34 2d 57 4e 44 53 4f 4e 31 37
ppp: [wan_link0] LCP: LayerDown
ppp: [wan_link0] LCP: SendConfigReq #3
ppp: [wan_link0]   PROTOCOMP
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   MAGICNUM 2458176a
ppp: [wan_link0] LCP: SendConfigAck #1
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   AUTHPROTO PAP
ppp: [wan_link0]   MAGICNUM c0c24075
ppp: [wan_link0]   MP MRRU 1524
ppp: [wan_link0]   ENDPOINTDISC [LOCAL] 6c 6e 73 34 2d 57 4e 44 53 4f 4e 31 37
ppp: [wan_link0] LCP: state change Opened --> Ack-Sent
ppp: [wan_link0] LCP: phase shift AUTHENTICATE --> ESTABLISH
ppp: [wan_link0] AUTH: Cleanup
ppp: [wan_link1] LCP: rec'd Configure Ack #3 (Ack-Sent)
ppp: [wan_link1]   PROTOCOMP
ppp: [wan_link1]   MRU 1492
ppp: [wan_link1]   MAGICNUM 27336dd6
ppp: [wan_link1] LCP: state change Ack-Sent --> Opened
ppp: [wan_link1] LCP: phase shift ESTABLISH --> AUTHENTICATE
ppp: [wan_link1] LCP: auth: peer wants PAP, I want nothing
ppp: [wan_link1] PAP: using authname "mppp%user@mnsi.net"
ppp: [wan_link1] PAP: sending REQUEST #1 len: 36
ppp: [wan_link1] LCP: LayerUp
ppp: [wan_link0] LCP: rec'd Configure Ack #3 (Ack-Sent)
ppp: [wan_link0]   PROTOCOMP
ppp: [wan_link0]   MRU 1492
ppp: [wan_link0]   MAGICNUM 2458176a
ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
ppp: [wan_link0] LCP: phase shift ESTABLISH --> AUTHENTICATE
ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
ppp: [wan_link0] PAP: using authname "mppp%user@mnsi.net"
ppp: [wan_link0] PAP: sending REQUEST #1 len: 36
ppp: [wan_link0] LCP: LayerUp
ppp: [wan_link1] PAP: rec'd ACK #1 len: 5
ppp: [wan_link1] LCP: authorization successful
ppp: [wan_link1] LCP: phase shift AUTHENTICATE --> NETWORK
ppp: [wan_link1] Link: Matched action 'bundle "wan" ""'
ppp: [wan_link1] Link: Join bundle "wan"
ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
ppp: [wan] IPCP: Open event
ppp: [wan] IPCP: state change Initial --> Starting
ppp: [wan] IPCP: LayerStart
ppp: [wan] IPCP: Up event
ppp: [wan] IPCP: state change Starting --> Req-Sent
ppp: [wan] IPCP: SendConfigReq #1
ppp: [wan]   IPADDR 0.0.0.0
ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
ppp: [wan]   IPADDR 216.8.136.171
ppp: [wan]     216.8.136.171 is OK
ppp: [wan] IPCP: SendConfigAck #1
ppp: [wan]   IPADDR 216.8.136.171
ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent
ppp: [wan_link0] PAP: rec'd ACK #1 len: 5
ppp: [wan_link0] LCP: authorization successful
ppp: [wan_link0] LCP: phase shift AUTHENTICATE --> NETWORK
ppp: [wan_link0] Can't join bundle wan without multilink negotiated.
ppp: [wan_link0] link did not validate in bundle
ppp: [wan_link0] LCP: parameter negotiation failed
ppp: [wan_link0] LCP: state change Opened --> Stopping
ppp: [wan_link0] LCP: phase shift NETWORK --> TERMINATE
ppp: [wan_link0] AUTH: Cleanup
ppp: [wan_link0] LCP: SendTerminateReq #4
ppp: [wan_link0] LCP: LayerDown
ppp: [wan_link0] rec'd proto IPCP during terminate phase
ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
ppp: [wan] IPCP: SendConfigReq #2
ppp: [wan]   IPADDR 0.0.0.0
ppp: [wan_link0] LCP: rec'd Terminate Ack #4 (Stopping)
ppp: [wan_link0] LCP: state change Stopping --> Stopped
ppp: [wan_link0] LCP: phase shift TERMINATE --> ESTABLISH
ppp: [wan_link0] LCP: LayerFinish
ppp: [wan_link0] PPPoE: connection closed
ppp: [wan_link0] Link: DOWN event
ppp: [wan_link0] LCP: Close event
ppp: [wan_link0] LCP: state change Stopped --> Closed
ppp: [wan_link0] LCP: Down event
ppp: [wan_link0] LCP: state change Closed --> Initial
ppp: [wan_link0] LCP: phase shift ESTABLISH --> DEAD
ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
ppp: [wan]   IPADDR MYIP
ppp: [wan]     MYIP is OK
ppp: [wan] IPCP: SendConfigReq #3
ppp: [wan]   IPADDR MYIP
ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
ppp: [wan]   IPADDR MYIP
ppp: [wan] IPCP: state change Ack-Sent --> Opened
ppp: [wan] IPCP: LayerUp
ppp: [wan]   MYIP -> GATEWAY
ppp: [wan] IFACE: Up event

I may be incorrect, but what I see is the following:

1. PPPoE session opens
2. mpd5 sends a config request to the access concentrator with the settings from mpd_wan.conf
3. ISP's access concentrator gets the config, negotiates a new MAGICNUM, and rejects MRRU and SHORTSEQ.
4. mpd5 renegotiates with the access concentrator without MRRU, without SHORTSEQ, and with the new MAGICNUM
5. mpd5 authenticates with my ISP using my username and password
6. mpd5 gets passed from the access concentrator to the access server.
7. ISP's access server sends a configuration request which has a new MAGICNUM, MRRU settings for MLPPP.
8. mpd5 resends the LCP parameters it negotiated with the access concentrator instead of negotiating the settings that the access server wants.
9. PPPoE session is established without multilink, and without the correct MAGICNUM that the access server requested.
10. mpd5 cannot join two links to the WAN bundle because it never negotiates multilink with the ISP.

The root cause is that mpd doesn't appear to respond correctly to the LCP renegotiation from the LNS. The LNS is doing the exact same thing to mpd that mpd attempted with the access concentrator, but mpd isn't behaving in a way that lets the LNS renegotiate LCP.

chpalmer

Saw your post yesterday over at the MPD site… Kinda wish I knew Russian over there... Thanks for the updates!

chpalmer

I find this interesting from the manual…

4.16. Web server

Mpd provides HTTP interface for monitoring and control purposes. This chapter describes commands for configuring Mpd's web server.

set web open

Opens the web server, i.e., creates the listening TCP socket.
set web close

Closes the web server, i.e., closes the listening TCP socket.
set web self ip [ port ]

Sets the credentials for the web-listener. After changing one of these options, the web must be closed and re-opened for the changes to take effect.

The default is '127.0.0.1 5006'.

set web enable option …
set web disable option ...

These commands configure various web server options.

The enable and disable commands determine whether we want the corresponding option.

The options available for the web are:
auth

This option enables basic authorisation on web server.

The default is enable.

You can send any set of command allowed by privileges via WEB server for mpd infrastructure integration. Depending on URL used mpd supports two response formats: text/html (/cmd?command1&...) and text/plain (/bincmd?command1&...).

Epoch

I saw that Mpd supports a bunch of cool options, but I have yet to find one that would help.
Basically, what I am seeing appears to be something that was fixed in 2008 in the mpd5 cvs, but maybe it didn't make its way into mpd5.5 in pfsense.

This is where I see the same issue diagnosed by one of the authors of mpd, and that he put a patch in to resolve this very issue.

Same issue, identified by Alexander Motin

Patched by Alexander Motin

That is what I don't understand, this issue appears to have been fixed over 3 years ago, but somehow I have this very problem. Maybe there is a recursion, I don't really know, but in theory it should impact Teksavvy users.

In theory, if a Teksavvy user restarted a mlppp session they should see in their logs similar things to what I have in mine, but it should renegotiate after the access concentrator. For some reason, mine won't. It probably wouldn't hurt to see those logs though and see if something is different since Teksavvy uses Juniper gear instead of Cisco gear.

clarknova

@Epoch:

It probably wouldn't hurt to see those logs though and see if something is different since Teksavvy uses Juniper gear instead of Cisco gear.

Enjoy.

ppp.log.txt

Epoch

There is one key difference in between your logs and mine:
"May 11 23:30:13 pfsense ppp: [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)"

When you hit the access server you get a CONFNAK or "Configure Negative Acknowledgement" message which renegotiates MRRU, it looks like I am not getting a CONFNAK message from my ISP and their gear.

clarknova

You may want to ask gnhb to look at this thread. I believe he did the bulk of the work getting mlppp into pfsense, so he may have some insight for you on this problem.

Epoch

That may be true, but it appears that the MNSi Cisco LNS isn't sending CONFIGURE-NAK back to my router which is the root cause of this issue, and it isn't rejecting the LCP parameters either.

clarknova

But presumably other users with other routers are able to use mlppp with your ISP's broken equipment. If this is the case, then perhaps pfsense could be made to as well.

Epoch

I know that other gear works, as between myself and the ISP there has been verification that Cisco gear works with them, as does Mikrotik gear.
In fact, my pfSense box is behind a Mikrotik router right now so that I can use multilink while I try and figure out why pfSense doesn't work.