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

    Sudden PPPoE failure

    General pfSense Questions
    5
    15
    3.9k
    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.
    • R
      Rob Beckers
      last edited by

      After working for 1-1/2 years without problem our PPPoE link with our provider went down. Luckily this happened in the weekend, giving me some time to troubleshoot. A laptop hooked up to the interface and set up for PPPoE has no problem, it logs in and works like a charm. A cheap DLink router likewise works fine. Thinking it was a hardware issue I swapped to an entirely different pfSense box, loaded the config, same problem, no PPPoE link!

      My Internet provider says they did not make any changes, and the last time I changed anything on this box was in December, yet the link suddenly failed and no matter what I try it won't come back up. I've deleted and re-created the PPPoE interface a dozen times in pfSense, removed all packages, no luck. The WAN remains down.

      For now I've put our business Internet on a DLink box but I can't use our VLANs with that and there's no packet filtering. I'd very much like my pfSense box back!

      This is on the latest version of pfSense, v2.2.6, 64-bit, Intel network interfaces. Vanilla hardware other than that (and note that I've tried two different boxes, completely different hardware, same problem). Our setup is for IPv4 only, I have IPv6 disabled for the interface. We normally pull a static IP.

      The PPP log shows the following, this is from a restart showing the full dialog. Unfortunately I don't know enough about the PPP protocol to make heads or tails from it (nothing stands out for me). Hopefully this makes sense to someone. It's rather long:

      Jan 31 16:57:42 ppp: [wan_link0] LCP: state change Closed –> Initial
      Jan 31 16:57:42 ppp: [wan_link0] LCP: Down event
      Jan 31 16:57:42 ppp: [wan_link0] Link: DOWN event
      Jan 31 16:57:42 ppp: [wan_link0] LCP: LayerFinish
      Jan 31 16:57:42 ppp: [wan_link0] LCP: state change Closing –> Closed
      Jan 31 16:57:42 ppp: [wan_link0] rec'd proto IPV6CP during terminate phase
      Jan 31 16:57:42 ppp: [wan_link0] rec'd proto IPCP during terminate phase
      Jan 31 16:57:40 ppp: [wan_link0] LCP: SendTerminateReq #10
      Jan 31 16:57:40 ppp: [wan_link0] rec'd proto IPV6CP during terminate phase
      Jan 31 16:57:40 ppp: [wan_link0] rec'd proto IPCP during terminate phase
      Jan 31 16:57:38 ppp: [wan_link0] LCP: LayerDown
      Jan 31 16:57:38 ppp: [wan_link0] LCP: SendTerminateReq #9
      Jan 31 16:57:38 ppp: [wan] IPV6CP: state change Closed –> Initial
      Jan 31 16:57:38 ppp: [wan] IPV6CP: Down event
      Jan 31 16:57:38 ppp: [wan] IPCP: state change Closed –> Initial
      Jan 31 16:57:38 ppp: [wan] IPCP: Down event
      Jan 31 16:57:38 ppp: [wan] IPV6CP: state change Stopped –> Closed
      Jan 31 16:57:38 ppp: [wan] IPV6CP: Close event
      Jan 31 16:57:38 ppp: [wan] IPCP: state change Stopped –> Closed
      Jan 31 16:57:38 ppp: [wan] IPCP: Close event
      Jan 31 16:57:38 ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
      Jan 31 16:57:38 ppp: [wan_link0] Link: Leave bundle "wan"
      Jan 31 16:57:38 ppp: [wan_link0] LCP: state change Opened –> Closing
      Jan 31 16:57:38 ppp: [wan_link0] LCP: Close event
      Jan 31 16:57:38 ppp: [wan_link0] Link: CLOSE event
      Jan 31 16:57:38 ppp: [wan] Bundle: closing link "wan_link0"…
      Jan 31 16:57:38 ppp: [wan] Bundle: No NCPs left. Closing links…
      Jan 31 16:57:38 ppp: [wan] IPCP: LayerFinish
      Jan 31 16:57:38 ppp: [wan] IPCP: state change Ack-Sent –> Stopped
      Jan 31 16:57:38 ppp: [wan] IPCP: parameter negotiation failed
      Jan 31 16:57:38 ppp: [wan] IPV6CP: LayerFinish
      Jan 31 16:57:38 ppp: [wan] IPV6CP: state change Ack-Sent –> Stopped
      Jan 31 16:57:38 ppp: [wan] IPV6CP: parameter negotiation failed
      Jan 31 16:57:36 ppp: [wan] IPV6CP: SendConfigReq #10
      Jan 31 16:57:36 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:36 ppp: [wan] IPCP: SendConfigReq #11
      Jan 31 16:57:34 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:34 ppp: [wan] IPCP: SendConfigReq #10
      Jan 31 16:57:34 ppp: [wan] IPV6CP: SendConfigReq #9
      Jan 31 16:57:32 ppp: [wan] IPV6CP: SendConfigReq #8
      Jan 31 16:57:32 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:32 ppp: [wan] IPCP: SendConfigReq #9
      Jan 31 16:57:30 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:30 ppp: [wan] IPCP: SendConfigReq #8
      Jan 31 16:57:30 ppp: [wan] IPV6CP: SendConfigReq #7
      Jan 31 16:57:28 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:28 ppp: [wan] IPCP: SendConfigReq #7
      Jan 31 16:57:28 ppp: [wan] IPV6CP: SendConfigReq #6
      Jan 31 16:57:26 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:26 ppp: [wan] IPCP: SendConfigReq #6
      Jan 31 16:57:26 ppp: [wan] IPV6CP: SendConfigReq #5
      Jan 31 16:57:24 ppp: [wan] IPV6CP: SendConfigReq #4
      Jan 31 16:57:24 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:24 ppp: [wan] IPCP: SendConfigReq #5
      Jan 31 16:57:22 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:22 ppp: [wan] IPCP: SendConfigReq #4
      Jan 31 16:57:22 ppp: [wan] IPV6CP: SendConfigReq #3
      Jan 31 16:57:20 ppp: [wan] IPV6CP: SendConfigReq #2
      Jan 31 16:57:20 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:20 ppp: [wan] IPCP: SendConfigReq #3
      Jan 31 16:57:18 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:18 ppp: [wan] IPCP: SendConfigReq #2
      Jan 31 16:57:18 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      Jan 31 16:57:18 ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan] IPV6CP: state change Req-Sent –> Ack-Sent
      Jan 31 16:57:18 ppp: [wan] IPV6CP: SendConfigAck #1
      Jan 31 16:57:18 ppp: [wan] IPV6CP: rec'd Configure Request #1 (Req-Sent)
      Jan 31 16:57:18 ppp: [wan] IPCP: state change Req-Sent –> Ack-Sent
      Jan 31 16:57:18 ppp: [wan] IPADDR 209.87.239.231
      Jan 31 16:57:18 ppp: [wan] IPCP: SendConfigAck #1
      Jan 31 16:57:18 ppp: [wan] 209.87.239.231 is OK
      Jan 31 16:57:18 ppp: [wan] IPADDR 209.87.239.231
      Jan 31 16:57:18 ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
      Jan 31 16:57:18 ppp: [wan] IPV6CP: SendConfigReq #1
      Jan 31 16:57:18 ppp: [wan] IPV6CP: state change Starting –> Req-Sent
      Jan 31 16:57:18 ppp: [wan] IPV6CP: Up event
      Jan 31 16:57:18 ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
      Jan 31 16:57:18 ppp: [wan] IPADDR 0.0.0.0
      Jan 31 16:57:18 ppp: [wan] IPCP: SendConfigReq #1
      Jan 31 16:57:18 ppp: [wan] IPCP: state change Starting –> Req-Sent
      Jan 31 16:57:18 ppp: [wan] IPCP: Up event
      Jan 31 16:57:18 ppp: [wan] IPV6CP: LayerStart
      Jan 31 16:57:18 ppp: [wan] IPV6CP: state change Initial –> Starting
      Jan 31 16:57:18 ppp: [wan] IPV6CP: Open event
      Jan 31 16:57:18 ppp: [wan] IPCP: LayerStart
      Jan 31 16:57:18 ppp: [wan] IPCP: state change Initial –> Starting
      Jan 31 16:57:18 ppp: [wan] IPCP: Open event
      Jan 31 16:57:18 ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
      Jan 31 16:57:18 ppp: [wan_link0] Link: Join bundle "wan"
      Jan 31 16:57:18 ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
      Jan 31 16:57:18 ppp: [wan_link0] LCP: authorization successful
      Jan 31 16:57:18 ppp: [wan_link0] PAP: rec'd ACK #1 len: 5
      Jan 31 16:57:18 ppp: [wan_link0] LCP: LayerUp
      Jan 31 16:57:18 ppp: [wan_link0] PAP: sending REQUEST #1 len: 31
      Jan 31 16:57:18 ppp: [wan_link0] PAP: using authname "solacity@storm.ca"
      Jan 31 16:57:18 ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Ack #8 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #8
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Reject #7 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #7
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1500
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Nak #6 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #6
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1500
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Nak #5 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #5
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1500
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Nak #4 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #4
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1500
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #3
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1500
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Nak #2 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Opened –> Ack-Sent
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM 2f9097bf
      Jan 31 16:57:18 ppp: [wan_link0] AUTHPROTO PAP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigAck #1
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #2
      Jan 31 16:57:18 ppp: [wan_link0] LCP: LayerDown
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM 2f9097bf
      Jan 31 16:57:18 ppp: [wan_link0] AUTHPROTO PAP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Request #1 (Opened)
      Jan 31 16:57:18 ppp: [wan_link0] LCP: LayerUp
      Jan 31 16:57:18 ppp: [wan_link0] PAP: sending REQUEST #1 len: 31
      Jan 31 16:57:18 ppp: [wan_link0] PAP: using authname "solacity@storm.ca"
      Jan 31 16:57:18 ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Ack-Sent –> Opened
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Req-Sent –> Ack-Sent
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM a4ac4a14
      Jan 31 16:57:18 ppp: [wan_link0] AUTHPROTO PAP
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigAck #1
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM a4ac4a14
      Jan 31 16:57:18 ppp: [wan_link0] AUTHPROTO PAP
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] LCP: rec'd Configure Request #1 (Req-Sent)
      Jan 31 16:57:18 ppp: [wan_link0] MAGICNUM daac27bf
      Jan 31 16:57:18 ppp: [wan_link0] MRU 1492
      Jan 31 16:57:18 ppp: [wan_link0] PROTOCOMP
      Jan 31 16:57:18 ppp: [wan_link0] LCP: SendConfigReq #1
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Starting –> Req-Sent
      Jan 31 16:57:18 ppp: [wan_link0] LCP: Up event
      Jan 31 16:57:18 ppp: [wan_link0] Link: UP event
      Jan 31 16:57:18 ppp: [wan_link0] PPPoE: connection successful
      Jan 31 16:57:18 ppp: PPPoE: rec'd ACNAME "wireless"
      Jan 31 16:57:18 ppp: [wan_link0] PPPoE: Connecting to ''
      Jan 31 16:57:18 ppp: [wan_link0] LCP: LayerStart
      Jan 31 16:57:18 ppp: [wan_link0] LCP: state change Initial –> Starting
      Jan 31 16:57:18 ppp: [wan_link0] LCP: Open event
      Jan 31 16:57:18 ppp: [wan_link0] Link: OPEN event
      Jan 31 16:57:18 ppp: [wan] Bundle: Interface ng0 created
      Jan 31 16:57:18 ppp: web: web is not running
      Jan 31 16:57:17 ppp: process 75177 terminated
      Jan 31 16:57:17 ppp: [wan_link0] Link: Shutdown
      Jan 31 16:57:17 ppp: [wan] Bundle: Shutdown
      Jan 31 16:57:17 ppp: waiting for process 75177 to die…
      Jan 31 16:57:15 ppp: [wan] IPV6CP: Close event
      Jan 31 16:57:15 ppp: [wan] IPCP: Close event
      Jan 31 16:57:15 ppp: [wan] IFACE: Close event
      Jan 31 16:57:15 ppp: caught fatal signal TERM
      Jan 31 16:57:15 ppp: waiting for process 75177 to die…
      Jan 31 16:57:15 ppp: process 81211 started, version 5.7 (root@pfSense_RELENG_2_2_amd64_amd64-pfSense_RELENG_2_2-job-03 20:05 21-Aug-2015)
      Jan 31 16:57:15 ppp:
      Jan 31 16:57:15 ppp: Multi-link PPP daemon for FreeBSD

      Thank you for any help or suggestions!

      -Rob-

      1 Reply Last reply Reply Quote 0
      • D
        David_W
        last edited by

        IPCP is failing to agree parameters.

        The first thing I'd do is disable compression (vjcomp) using Interfaces -> (assign), PPPs tab, pressing 'Show advanced options' when you are editing the connection. vjcomp is standard for dial-up modem links, but is very unlikely to be used with PPPoE or cellular connections. Don't forget to save and apply the change.

        It might just be that disabling vjcomp is sufficient for the IPCP layer to agree parameters. If not, post a new log - ideally the other way up (latest entries at the bottom) to make it easier to read.

        1 Reply Last reply Reply Quote 1
        • R
          Rob Beckers
          last edited by

          David, thank you very much for your quick reply!
          I tried disabling VJComp but that did not resolve it. The log showed it still had trouble negotiating parameters.

          That was as far as I got this morning. Our ISP sent people out at 8:30am and their solution was to put a switch between our pfSense box and their Internet link. Their switch takes care of setting up the PPP connection. That means pfSense is now set to just a plain fixed IP, and no longer needs to do PPP.

          This works, we're back up and running, but we'll never know why the PPPoE link suddenly failed, and what parameter was the problem. They maintain that no changes were done on their side, and I know I didn't change anything here. So the mystery remains.

          I am sorry that I cannot report back what to do in case others have the same problem. This is a production system so I don't want to mess around too much with it, and it works as it is now.

          Thanks!!

          -Rob-

          1 Reply Last reply Reply Quote 0
          • H
            hda
            last edited by

            MRU fight ?

            
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Reject #7 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
Jan 31 16:57:18    ppp: [wan_link0] PROTOCOMP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigReq #7
Jan 31 16:57:18    ppp: [wan_link0] MRU 1500
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Nak #6 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
Jan 31 16:57:18    ppp: [wan_link0] PROTOCOMP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigReq #6
Jan 31 16:57:18    ppp: [wan_link0] MRU 1500
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Nak #5 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
Jan 31 16:57:18    ppp: [wan_link0] PROTOCOMP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigReq #5
Jan 31 16:57:18    ppp: [wan_link0] MRU 1500
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Nak #4 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
Jan 31 16:57:18    ppp: [wan_link0] PROTOCOMP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigReq #4
Jan 31 16:57:18    ppp: [wan_link0] MRU 1500
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
Jan 31 16:57:18    ppp: [wan_link0] PROTOCOMP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigReq #3
Jan 31 16:57:18    ppp: [wan_link0] MRU 1500
Jan 31 16:57:18    ppp: [wan_link0] LCP: rec'd Configure Nak #2 (Ack-Sent)
Jan 31 16:57:18    ppp: [wan_link0] LCP: state change Opened --> Ack-Sent
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM 2f9097bf
Jan 31 16:57:18    ppp: [wan_link0] AUTHPROTO PAP
Jan 31 16:57:18    ppp: [wan_link0] LCP: SendConfigAck #1
Jan 31 16:57:18    ppp: [wan_link0] MAGICNUM daac27bf
Jan 31 16:57:18    ppp: [wan_link0] MRU 1492
            1 Reply Last reply Reply Quote 0
            • D
              David_W
              last edited by

              It is certainly a mystery why the remote end is insisting on an MRU of 1500 and refuses repeated requests from pfSense for a MRU of 1492. I was hoping getting rid of pfSense's request for VJ Compression would allow both sides to agree on MRU 1492 with no VJ Compression.

              MRU 1500 operation over PPPoE requires RFC 4638 support, which is only available in recent pfSense 2.3 snapshots or by installing my unofficial RFC 4638 patch for 2.2.x.

              1 Reply Last reply Reply Quote 0
              • R
                Rob Beckers
                last edited by

                Thanks for your continued looking-into David!
                My feeling is that settings were changed on their PPP server, though they continue to claim no changes were made. They're probably not aware that their PPP server is asking for an unusual MRU size. Since my pfSense box is no longer doing PPP I can't verify things, the PPP connection is now handled by a switch between pfSense and their network (and it's the ISPs switch so I'm not going to touch it). This solution works for me, so I have to leave it at that.

                I do very much appreciate everyone's help though!

                -Rob-

                1 Reply Last reply Reply Quote 0
                • A
                  adamsaint
                  last edited by

                  Hi Rob I had exactly the same problem.  on that saturday the 31st a router I have running for my dad couldnt connect anymore at 4:13am  (Ottawa Canada)  ISP is storm.  this seems to be exactly the same, right down the line.

                  Dave I too ready about the issues that seem to be resolved in version 2.3.  I realize it isnt released yet but I was hoping to get a copy of 2.3 to see if it works better.

                  Rob… could you tell me what the switch you got placed in front of your pfsense box is?  at this point for my dad, Im going over there this weekend and Ill just go buy him one and set things up on it if need be.

                  1 Reply Last reply Reply Quote 0
                  • R
                    Rob Beckers
                    last edited by

                    Hi Adam,

                    That's interesting! All indications are that Storm changed PPPoE parameters, the MRU setting in particular as David pointed out, and that broke PPPoE in pfSense. Storm denied any changes, but with both of us having the same issue it seems improbable in the extreme that it's on our end. Heck, who knows, someone who shouldn't be touching the system at Storm may inadvertently have made a change and not told anyone about it. Stranger things have happened.

                    I will take a look at the brand and type of switch Storm put in at my site on Tuesday (this is a business install of pfSense) and let you know. You can also just call Storm and tell them what's happening. By now they must have had several customers with the same issue. Their tech support has been excellent (as is their network service, we never have bandwidth/latency/dropped-packet issues), they were very responsive when I called them. They have someone in the weekend as well picking up the phone.

                    -Rob-

                    1 Reply Last reply Reply Quote 0
                    • A
                      adamsaint
                      last edited by

                      Hi Rob,

                      I thought it might be that you were on Storm as well.  Generally I have to agree they are fairly good for service.  when it happened I suggested to my dad that he do the basic stuff.  turn it off, then on etc.  eventually when I checked and found everything OK AND checked my own laptop worked.  I called to ask if something had changed.  this was shortly afterwards and so I suspect not many people are in the same shoes as you and I.  pfsense is popular but not nearly so much as basic dlink/linksys/belcan/netgear etc. routers.  when the fellow from storm made the point that if other routers and my laptop work it isn't something wrong with there service I cant help but to agree.  this article, your explaining the issue AND David W. weighing in with some further explanation of pfsense not being able to negotiate mru/mtu exactly right in the versions we are using definitely makes sense.  so, after seeing that in version 2.3 (still BETA) the issue is mentioned in the fixes, I got a snapshot and built a new router to go over to my dads place today, all ready to go and I have to say, the GUI for 2.3 looks pretty nice.  so Ill try it out, if it works than Ill leave it in play for now and Ill let you know the result back in here as well.  if not, knowing the type of machine they put in place for you would be handy..  I'm guessing at maybe some basic mikrotik 50$ kind of router that is simply doing the pppoe part and bridging??  anyways, I agree also that by this point, 2+ weeks later, Storm might be worth another shot to ask if they now are aware of any issues coming from a chance with how pppoe is working out mtu and mru that they could deal with..  (Ill actually try the old router first to see if such knowledge might have led someone to correct the issue between today and last time I was there)

                      I have to thank David regardless of the result for seeing this as an issue and working out a patch.  the router Im looking at unfortunately wont do amd64, its purely i386 so I cannot use that patch but I am trying out 2.3 of pfsense (a buld from yesterday).  Thanks David for working it out..  this was veyr much driving me mad and just seeing that you and Rob saw the same somewhat obscure issue is a relief…  I was having a really tough time seeing how it added up.

                      1 Reply Last reply Reply Quote 0
                      • chpalmerC
                        chpalmer
                        last edited by

                        Are you guys using an MLPPP connection?  Your logs seem to indicate you are.

                        Triggering snowflakes one by one..
                        Intel(R) Core(TM) i5-4590T CPU @ 2.00GHz on an M400 WG box.

                        1 Reply Last reply Reply Quote 0
                        • R
                          Rob Beckers
                          last edited by

                          @chpalmer:

                          Are you guys using an MLPPP connection?  Your logs seem to indicate you are.

                          PPP is something I've never really looked into in any detail, I don't know much about it. With that in mind: It does look like it's doing MLPPP. Since it seems to be negotiation multiple channels. Possibly that's how the ISP does bandwidth control? They have multiple tiers for their subscriptions, we pay for 10 Mbps down, 5 Mbps up, they have other options as well, and a higher-speed tier could just mean more channels. This is all via wireless modems.

                          Since my pfSense box no longer does PPP I can't log a successful PPP handshake, and I never bothered to log one when it was still working. So, can't tell you for sure.

                          Adam, let me know how v2.3 works out! I can no longer test PPP, since we have a working solution (and this is production system, I don't want to mess with it too much). It is curious how the cheap routers (D-Link etc.) have no trouble negotiating a PPP connection. Maybe those manufacturers learned not to make their implementation too standards-compliant, and they will accept parameters that would normally violate the rules, where pfSense is more picky. Just speculating…

                          -Rob-

                          1 Reply Last reply Reply Quote 0
                          • A
                            adamsaint
                            last edited by

                            Good Afternoon,

                            Chpalmer.  nope only one connection, no MLPPP

                            Rob.  I tried..  but no joy.  so I prepared another box with the i386 version of 2.3 loaded and only the very basic settings for testing purposes I didnt put the entire config into it.  only basic settup with the pppoe username/password to see how this went in as clean an experiment as possible.  it failed though with just the same sequence of logging as 2.2.6.  Im guessing that this means either the fix isnt fixed as well as I hoped, or that the fix is still in the works.

                            From reading the related bug tracking and material from David.  it seems that this really is a problem, maybe somewhat obscure, with pfsense in being unable to negotiate MRU/MTU fully when above 1492.  so its an issue that has pfsense deviating from the standard a little, unless I read it wrong.  Rob your case and mine is it seems that the pppoe server wants to use something pfsense cant handle in this version.  when I saw the issue in bug fixes for 2.3 I was really excited to get a fix.. but I think perhaps a litte more time for that fix is whats in order…

                            so my choices for a fix I think at this point come down to one fo three things.

                            • build a new box and put the 64 bit version of 2.2.6 on it, then use David's Patch.
                            • keep checking on the progress of 2.3 and when its ready with this issue resolved, go that way.
                            • or put another box infront of the pfsense box to take care of the pppoe part  and somehow pass the public IP through?  actually not sure how this was done for you Rob, if you get a chance when you are back to the office tomorrow Id certainly be interested on what they did for you.
                            • or finally.  I can try to take it up with Storm again.  I might well do that tomorrow, however because it effect both of us.  I'm guessing its a global type of change at the pppoe server level..  not just something on the tower at my dads place...  an they have not made a global change to go back or to accommodate here yet.  so I doubt they will make an exception other than maybe some kind of box like you mentioned Rob to handle the PPPoE separately..  im dealing with a residential account so they will likly be less inclined to go to the same lengths.

                            any other suggestions would be great.

                            I captured some logging here of the failure after putting 2.3 in place... I realize this is rather dry...  so sorry in advance.

                            Feb 14 20:53:24 ppp process 6056 started, version 5.8 (root@pfSense_master_i386_i386-pfSense_master-job-01 19:11 6-Jan-2016)
                            Feb 14 20:53:24 ppp web: web is not running
                            Feb 14 20:53:24 ppp [wan] Bundle: Interface ng0 created
                            Feb 14 20:53:24 ppp [wan_link0] Link: OPEN event
                            Feb 14 20:53:24 ppp [wan_link0] LCP: Open event
                            Feb 14 20:53:24 ppp [wan_link0] LCP: state change Initial –> Starting
                            Feb 14 20:53:24 ppp [wan_link0] LCP: LayerStart
                            Feb 14 20:53:24 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:53:33 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:53:33 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:53:33 ppp [wan_link0] LCP: Down event
                            Feb 14 20:53:33 ppp [wan_link0] Link: reconnection attempt 1 in 2 seconds
                            Feb 14 20:53:35 ppp [wan_link0] Link: reconnection attempt 1
                            Feb 14 20:53:35 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:53:44 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:53:44 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:53:44 ppp [wan_link0] LCP: Down event
                            Feb 14 20:53:44 ppp [wan_link0] Link: reconnection attempt 2 in 1 seconds
                            Feb 14 20:53:45 ppp [wan_link0] Link: reconnection attempt 2
                            Feb 14 20:53:45 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:53:54 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:53:54 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:53:54 ppp [wan_link0] LCP: Down event
                            Feb 14 20:53:54 ppp [wan_link0] Link: reconnection attempt 3 in 1 seconds
                            Feb 14 20:53:55 ppp [wan_link0] Link: reconnection attempt 3
                            Feb 14 20:53:55 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:54:04 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:54:04 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:54:04 ppp [wan_link0] LCP: Down event
                            Feb 14 20:54:04 ppp [wan_link0] Link: reconnection attempt 4 in 1 seconds
                            Feb 14 20:54:05 ppp [wan_link0] Link: reconnection attempt 4
                            Feb 14 20:54:05 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:54:14 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:54:14 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:54:14 ppp [wan_link0] LCP: Down event
                            Feb 14 20:54:14 ppp [wan_link0] Link: reconnection attempt 5 in 2 seconds
                            Feb 14 20:54:16 ppp [wan_link0] Link: reconnection attempt 5
                            Feb 14 20:54:16 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:54:25 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:54:25 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:54:25 ppp [wan_link0] LCP: Down event
                            Feb 14 20:54:25 ppp [wan_link0] Link: reconnection attempt 6 in 2 seconds
                            Feb 14 20:54:27 ppp [wan_link0] Link: reconnection attempt 6
                            Feb 14 20:54:27 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:54:36 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:54:36 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:54:36 ppp [wan_link0] LCP: Down event
                            Feb 14 20:54:36 ppp [wan_link0] Link: reconnection attempt 7 in 4 seconds
                            Feb 14 20:54:40 ppp [wan_link0] Link: reconnection attempt 7
                            Feb 14 20:54:40 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:54:49 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:54:49 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:54:49 ppp [wan_link0] LCP: Down event
                            Feb 14 20:54:49 ppp [wan_link0] Link: reconnection attempt 8 in 4 seconds
                            Feb 14 20:54:53 ppp [wan_link0] Link: reconnection attempt 8
                            Feb 14 20:54:53 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:55:02 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:55:02 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:55:02 ppp [wan_link0] LCP: Down event
                            Feb 14 20:55:02 ppp [wan_link0] Link: reconnection attempt 9 in 4 seconds
                            Feb 14 20:55:06 ppp [wan_link0] Link: reconnection attempt 9
                            Feb 14 20:55:06 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:55:15 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:55:15 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:55:15 ppp [wan_link0] LCP: Down event
                            Feb 14 20:55:15 ppp [wan_link0] Link: reconnection attempt 10 in 2 seconds
                            Feb 14 20:55:17 ppp [wan_link0] Link: reconnection attempt 10
                            Feb 14 20:55:17 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:55:26 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:55:26 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:55:26 ppp [wan_link0] LCP: Down event
                            Feb 14 20:55:26 ppp [wan_link0] Link: reconnection attempt 11 in 4 seconds
                            Feb 14 20:55:30 ppp [wan_link0] Link: reconnection attempt 11
                            Feb 14 20:55:30 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:55:39 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:55:39 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:55:39 ppp [wan_link0] LCP: Down event
                            Feb 14 20:55:39 ppp [wan_link0] Link: reconnection attempt 12 in 1 seconds
                            Feb 14 20:55:40 ppp [wan_link0] Link: reconnection attempt 12
                            Feb 14 20:55:40 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:55:49 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:55:49 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:55:49 ppp [wan_link0] LCP: Down event
                            Feb 14 20:55:49 ppp [wan_link0] Link: reconnection attempt 13 in 3 seconds
                            Feb 14 20:55:52 ppp [wan_link0] Link: reconnection attempt 13
                            Feb 14 20:55:52 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:01 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:01 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:01 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:01 ppp [wan_link0] Link: reconnection attempt 14 in 1 seconds
                            Feb 14 20:56:02 ppp [wan_link0] Link: reconnection attempt 14
                            Feb 14 20:56:02 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:12 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:12 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:12 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:12 ppp [wan_link0] Link: reconnection attempt 15 in 1 seconds
                            Feb 14 20:56:13 ppp [wan_link0] Link: reconnection attempt 15
                            Feb 14 20:56:13 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:22 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:22 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:22 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:22 ppp [wan_link0] Link: reconnection attempt 16 in 3 seconds
                            Feb 14 20:56:25 ppp [wan_link0] Link: reconnection attempt 16
                            Feb 14 20:56:25 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:34 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:34 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:34 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:34 ppp [wan_link0] Link: reconnection attempt 17 in 3 seconds
                            Feb 14 20:56:37 ppp [wan_link0] Link: reconnection attempt 17
                            Feb 14 20:56:37 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:46 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:46 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:46 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:46 ppp [wan_link0] Link: reconnection attempt 18 in 2 seconds
                            Feb 14 20:56:48 ppp [wan_link0] Link: reconnection attempt 18
                            Feb 14 20:56:48 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:56:57 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:56:57 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:56:57 ppp [wan_link0] LCP: Down event
                            Feb 14 20:56:57 ppp [wan_link0] Link: reconnection attempt 19 in 1 seconds
                            Feb 14 20:56:58 ppp [wan_link0] Link: reconnection attempt 19
                            Feb 14 20:56:58 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:57:07 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:57:07 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:57:07 ppp [wan_link0] LCP: Down event
                            Feb 14 20:57:07 ppp [wan_link0] Link: reconnection attempt 20 in 1 seconds
                            Feb 14 20:57:08 ppp [wan_link0] Link: reconnection attempt 20
                            Feb 14 20:57:08 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:57:17 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:57:17 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:57:17 ppp [wan_link0] LCP: Down event
                            Feb 14 20:57:17 ppp [wan_link0] Link: reconnection attempt 21 in 2 seconds
                            Feb 14 20:57:19 ppp [wan_link0] Link: reconnection attempt 21
                            Feb 14 20:57:19 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:57:28 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:57:28 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:57:28 ppp [wan_link0] LCP: Down event
                            Feb 14 20:57:28 ppp [wan_link0] Link: reconnection attempt 22 in 4 seconds
                            Feb 14 20:57:32 ppp [wan_link0] Link: reconnection attempt 22
                            Feb 14 20:57:32 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:57:41 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:57:41 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:57:41 ppp [wan_link0] LCP: Down event
                            Feb 14 20:57:41 ppp [wan_link0] Link: reconnection attempt 23 in 3 seconds
                            Feb 14 20:57:44 ppp [wan_link0] Link: reconnection attempt 23
                            Feb 14 20:57:44 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:57:53 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:57:53 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:57:53 ppp [wan_link0] LCP: Down event
                            Feb 14 20:57:53 ppp [wan_link0] Link: reconnection attempt 24 in 1 seconds
                            Feb 14 20:57:54 ppp [wan_link0] Link: reconnection attempt 24
                            Feb 14 20:57:54 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:03 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:58:03 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:58:03 ppp [wan_link0] LCP: Down event
                            Feb 14 20:58:03 ppp [wan_link0] Link: reconnection attempt 25 in 4 seconds
                            Feb 14 20:58:07 ppp [wan_link0] Link: reconnection attempt 25
                            Feb 14 20:58:07 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:16 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:58:16 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:58:16 ppp [wan_link0] LCP: Down event
                            Feb 14 20:58:16 ppp [wan_link0] Link: reconnection attempt 26 in 4 seconds
                            Feb 14 20:58:20 ppp [wan_link0] Link: reconnection attempt 26
                            Feb 14 20:58:20 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:29 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:58:29 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:58:29 ppp [wan_link0] LCP: Down event
                            Feb 14 20:58:29 ppp [wan_link0] Link: reconnection attempt 27 in 3 seconds
                            Feb 14 20:58:32 ppp [wan_link0] Link: reconnection attempt 27
                            Feb 14 20:58:32 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:41 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:58:41 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:58:41 ppp [wan_link0] LCP: Down event
                            Feb 14 20:58:41 ppp [wan_link0] Link: reconnection attempt 28 in 1 seconds
                            Feb 14 20:58:42 ppp [wan_link0] Link: reconnection attempt 28
                            Feb 14 20:58:42 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:51 ppp [wan_link0] PPPoE connection timeout after 9 seconds
                            Feb 14 20:58:51 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:58:51 ppp [wan_link0] LCP: Down event
                            Feb 14 20:58:51 ppp [wan_link0] Link: reconnection attempt 29 in 3 seconds
                            Feb 14 20:58:54 ppp [wan_link0] Link: reconnection attempt 29
                            Feb 14 20:58:54 ppp [wan_link0] PPPoE: Connecting to ''
                            Feb 14 20:58:56 ppp PPPoE: rec'd ACNAME "wireless"
                            Feb 14 20:58:56 ppp [wan_link0] PPPoE: connection successful
                            Feb 14 20:58:56 ppp [wan_link0] Link: UP event
                            Feb 14 20:58:56 ppp [wan_link0] LCP: Up event
                            Feb 14 20:58:56 ppp [wan_link0] LCP: state change Starting –> Req-Sent
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #1
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Request #1 (Req-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] AUTHPROTO PAP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0xec9aee7b
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigAck #1
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] AUTHPROTO PAP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0xec9aee7b
                            Feb 14 20:58:56 ppp [wan_link0] LCP: state change Req-Sent –> Ack-Sent
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: state change Ack-Sent –> Opened
                            Feb 14 20:58:56 ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing
                            Feb 14 20:58:56 ppp [wan_link0] PAP: using authname "dsaint@storm.ca"
                            Feb 14 20:58:56 ppp [wan_link0] PAP: sending REQUEST #1 len: 29
                            Feb 14 20:58:56 ppp [wan_link0] LCP: LayerUp
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Request #1 (Opened)
                            Feb 14 20:58:56 ppp [wan_link0] AUTHPROTO PAP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x77d1c9cf
                            Feb 14 20:58:56 ppp [wan_link0] LCP: LayerDown
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #2
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigAck #1
                            Feb 14 20:58:56 ppp [wan_link0] AUTHPROTO PAP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x77d1c9cf
                            Feb 14 20:58:56 ppp [wan_link0] LCP: state change Opened –> Ack-Sent
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Nak #2 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1500
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #3
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1500
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #4
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Nak #4 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1500
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #5
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Nak #5 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1500
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #6
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Nak #6 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1500
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #7
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Reject #7 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] MRU 1492
                            Feb 14 20:58:56 ppp [wan_link0] LCP: SendConfigReq #8
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: rec'd Configure Ack #8 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan_link0] PROTOCOMP
                            Feb 14 20:58:56 ppp [wan_link0] MAGICNUM 0x08a63110
                            Feb 14 20:58:56 ppp [wan_link0] LCP: state change Ack-Sent –> Opened
                            Feb 14 20:58:56 ppp [wan_link0] LCP: auth: peer wants PAP, I want nothing
                            Feb 14 20:58:56 ppp [wan_link0] PAP: using authname "dsaint@storm.ca"
                            Feb 14 20:58:56 ppp [wan_link0] PAP: sending REQUEST #1 len: 29
                            Feb 14 20:58:56 ppp [wan_link0] LCP: LayerUp
                            Feb 14 20:58:56 ppp [wan_link0] PAP: rec'd ACK #1 len: 5
                            Feb 14 20:58:56 ppp [wan_link0] LCP: authorization successful
                            Feb 14 20:58:56 ppp [wan_link0] Link: Matched action 'bundle "wan" ""'
                            Feb 14 20:58:56 ppp [wan_link0] Link: Join bundle "wan"
                            Feb 14 20:58:56 ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
                            Feb 14 20:58:56 ppp [wan] IPCP: Open event
                            Feb 14 20:58:56 ppp [wan] IPCP: state change Initial –> Starting
                            Feb 14 20:58:56 ppp [wan] IPCP: LayerStart
                            Feb 14 20:58:56 ppp [wan] IPV6CP: Open event
                            Feb 14 20:58:56 ppp [wan] IPV6CP: state change Initial –> Starting
                            Feb 14 20:58:56 ppp [wan] IPV6CP: LayerStart
                            Feb 14 20:58:56 ppp [wan] IPCP: Up event
                            Feb 14 20:58:56 ppp [wan] IPCP: state change Starting –> Req-Sent
                            Feb 14 20:58:56 ppp [wan] IPCP: SendConfigReq #1
                            Feb 14 20:58:56 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:58:56 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
                            Feb 14 20:58:56 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:58:56 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:58:56 ppp [wan] IPV6CP: Up event
                            Feb 14 20:58:56 ppp [wan] IPV6CP: state change Starting –> Req-Sent
                            Feb 14 20:58:56 ppp [wan] IPV6CP: SendConfigReq #1
                            Feb 14 20:58:56 ppp [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
                            Feb 14 20:58:56 ppp [wan] IPADDR 209.87.239.231
                            Feb 14 20:58:56 ppp [wan] 209.87.239.231 is OK
                            Feb 14 20:58:56 ppp [wan] IPCP: SendConfigAck #1
                            Feb 14 20:58:56 ppp [wan] IPADDR 209.87.239.231
                            Feb 14 20:58:56 ppp [wan] IPCP: state change Req-Sent –> Ack-Sent
                            Feb 14 20:58:56 ppp [wan] IPV6CP: rec'd Configure Request #1 (Req-Sent)
                            Feb 14 20:58:56 ppp [wan] IPV6CP: SendConfigAck #1
                            Feb 14 20:58:56 ppp [wan] IPV6CP: state change Req-Sent –> Ack-Sent
                            Feb 14 20:58:56 ppp [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
                            Feb 14 20:58:56 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
                            Feb 14 20:58:56 ppp [wan] IPCP: SendConfigReq #2
                            Feb 14 20:58:56 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:58:56 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:58:56 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:58:58 ppp [wan] IPCP: SendConfigReq #3
                            Feb 14 20:58:58 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:58:58 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:58:58 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:58:58 ppp [wan] IPV6CP: SendConfigReq #2
                            Feb 14 20:59:00 ppp [wan] IPV6CP: SendConfigReq #3
                            Feb 14 20:59:00 ppp [wan] IPCP: SendConfigReq #4
                            Feb 14 20:59:00 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:00 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:00 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:02 ppp [wan] IPCP: SendConfigReq #5
                            Feb 14 20:59:02 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:02 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:02 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:02 ppp [wan] IPV6CP: SendConfigReq #4
                            Feb 14 20:59:04 ppp [wan] IPV6CP: SendConfigReq #5
                            Feb 14 20:59:04 ppp [wan] IPCP: SendConfigReq #6
                            Feb 14 20:59:04 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:04 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:04 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:06 ppp [wan] IPCP: SendConfigReq #7
                            Feb 14 20:59:06 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:06 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:06 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:06 ppp [wan] IPV6CP: SendConfigReq #6
                            Feb 14 20:59:08 ppp [wan] IPV6CP: SendConfigReq #7
                            Feb 14 20:59:08 ppp [wan] IPCP: SendConfigReq #8
                            Feb 14 20:59:08 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:08 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:08 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:10 ppp [wan] IPCP: SendConfigReq #9
                            Feb 14 20:59:10 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:10 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:10 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:10 ppp [wan] IPV6CP: SendConfigReq #8
                            Feb 14 20:59:12 ppp [wan] IPV6CP: SendConfigReq #9
                            Feb 14 20:59:12 ppp [wan] IPCP: SendConfigReq #10
                            Feb 14 20:59:12 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:12 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:12 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:14 ppp [wan] IPCP: SendConfigReq #11
                            Feb 14 20:59:14 ppp [wan] IPADDR 0.0.0.0
                            Feb 14 20:59:14 ppp [wan] PRIDNS 0.0.0.0
                            Feb 14 20:59:14 ppp [wan] SECDNS 0.0.0.0
                            Feb 14 20:59:14 ppp [wan] IPV6CP: SendConfigReq #10
                            Feb 14 20:59:16 ppp [wan] IPV6CP: parameter negotiation failed
                            Feb 14 20:59:16 ppp [wan] IPV6CP: state change Ack-Sent –> Stopped
                            Feb 14 20:59:16 ppp [wan] IPV6CP: LayerFinish
                            Feb 14 20:59:16 ppp [wan] IPCP: parameter negotiation failed
                            Feb 14 20:59:16 ppp [wan] IPCP: state change Ack-Sent –> Stopped
                            Feb 14 20:59:16 ppp [wan] IPCP: LayerFinish
                            Feb 14 20:59:16 ppp [wan] Bundle: No NCPs left. Closing links…
                            Feb 14 20:59:16 ppp [wan] Bundle: closing link "wan_link0"…
                            Feb 14 20:59:16 ppp [wan_link0] Link: CLOSE event
                            Feb 14 20:59:16 ppp [wan_link0] LCP: Close event
                            Feb 14 20:59:16 ppp [wan_link0] LCP: state change Opened –> Closing
                            Feb 14 20:59:16 ppp [wan_link0] Link: Leave bundle "wan"
                            Feb 14 20:59:16 ppp [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
                            Feb 14 20:59:16 ppp [wan] IPCP: Close event
                            Feb 14 20:59:16 ppp [wan] IPCP: state change Stopped –> Closed
                            Feb 14 20:59:16 ppp [wan] IPV6CP: Close event
                            Feb 14 20:59:16 ppp [wan] IPV6CP: state change Stopped –> Closed
                            Feb 14 20:59:16 ppp [wan] IPCP: Down event
                            Feb 14 20:59:16 ppp [wan] IPCP: state change Closed –> Initial
                            Feb 14 20:59:16 ppp [wan] IPV6CP: Down event
                            Feb 14 20:59:16 ppp [wan] IPV6CP: state change Closed –> Initial
                            Feb 14 20:59:16 ppp [wan_link0] LCP: SendTerminateReq #9
                            Feb 14 20:59:16 ppp [wan_link0] LCP: LayerDown
                            Feb 14 20:59:18 ppp [wan_link0] rec'd proto IPCP during terminate phase
                            Feb 14 20:59:18 ppp [wan_link0] rec'd proto IPV6CP during terminate phase
                            Feb 14 20:59:18 ppp [wan_link0] LCP: SendTerminateReq #10
                            Feb 14 20:59:20 ppp [wan_link0] rec'd proto IPCP during terminate phase
                            Feb 14 20:59:20 ppp [wan_link0] rec'd proto IPV6CP during terminate phase
                            Feb 14 20:59:20 ppp [wan_link0] LCP: state change Closing –> Closed
                            Feb 14 20:59:20 ppp [wan_link0] LCP: LayerFinish
                            Feb 14 20:59:20 ppp [wan_link0] Link: DOWN event
                            Feb 14 20:59:20 ppp [wan_link0] LCP: Down event
                            Feb 14 20:59:20 ppp [wan_link0] LCP: state change Closed –> Initial

                            1 Reply Last reply Reply Quote 0
                            • R
                              Rob Beckers
                              last edited by

                              I just read through RFC4638, it describes a mechanism to allow for PPP MTU's over 1492 bytes, and my understanding from that is that the PPP server MUST support a request for 1492 bytes. Only when both sides have indicated that they can handle a larger MTU can that be negotiated. If my understanding is correct then forcing an MTU of 1500 bytes down the throat of the PPP client is a violation of the standards. Even if the next version of pfSense supports larger MTUs it looks like this PPP server is not standards-compliant and therefore likely won't work with clients that adhere strictly.

                              Sooo… That would still bring us back to the theory that someone changed a PPP server parameter without really knowing what they were doing. Thereby breaking standards-compliant PPP clients. It is odd though that your average cheap router has no trouble with this PPP server.

                              I'm back at the business tomorrow and will take a look at the equipment Storm put in to solve it for us.

                              -Rob-

                              1 Reply Last reply Reply Quote 0
                              • chpalmerC
                                chpalmer
                                last edited by

                                MLPPP will do 1500.  Looks to me that your ISP flipped the wrong switch.

                                When I had MLPPP I had logs similar to yours. Now I have bonded service from my ISP and bonded by the modem that I have in bridge mode. My box doing pppoe logs differently now.

                                Feb 14 13:57:09					  ppp					  
  [wan] IPCP: state change Initial --> Starting					    Feb 14 13:57:09					  ppp					  
  [wan] IPCP: LayerStart					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: Open event					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: state change Initial --> Starting					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: LayerStart					    Feb 14 13:57:09					  ppp					  
  [wan] IPCP: Up event					    Feb 14 13:57:09					  ppp					  
  [wan] IPCP: state change Starting --> Req-Sent					    Feb 14 13:57:09					  ppp					  
  [wan] IPCP: SendConfigReq #1					    Feb 14 13:57:09					  ppp					  
  [wan]   IPADDR 0.0.0.0					    Feb 14 13:57:09					  ppp					  
  [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid					    Feb 14 13:57:09					  ppp					  
  [wan]   PRIDNS 0.0.0.0					    Feb 14 13:57:09					  ppp					  
  [wan]   SECDNS 0.0.0.0					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: Up event					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: state change Starting --> Req-Sent					    Feb 14 13:57:09					  ppp					  
  [wan] IPV6CP: SendConfigReq #1					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: rec'd Configure Reject #1 (Req-Sent)					    Feb 14 13:57:10					  ppp					  
  [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: SendConfigReq #2					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 0.0.0.0					    Feb 14 13:57:10					  ppp					  
  [wan]   PRIDNS 0.0.0.0					    Feb 14 13:57:10					  ppp					  
  [wan]   SECDNS 0.0.0.0					    Feb 14 13:57:10					  ppp					  
  [wan_link0] LCP: rec'd Protocol Reject #56 (Opened)					    Feb 14 13:57:10					  ppp					  
  [wan_link0] LCP: protocol IPV6CP was rejected					    Feb 14 13:57:10					  ppp					  
  [wan] IPV6CP: protocol was rejected by peer					    Feb 14 13:57:10					  ppp					  
  [wan] IPV6CP: state change Req-Sent --> Stopped					    Feb 14 13:57:10					  ppp					  
  [wan] IPV6CP: LayerFinish					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: rec'd Configure Request #58 (Req-Sent)					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 63.231.xx.xx					    Feb 14 13:57:10					  ppp					  
  [wan]     63.231.xx.xx is OK					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: SendConfigAck #58					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 63.231.xx.xx					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: state change Req-Sent --> Ack-Sent					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 174.xx.xx.xx					    Feb 14 13:57:10					  ppp					  
  [wan]     174.xx.xx.xx is OK					    Feb 14 13:57:10					  ppp					  
  [wan]   PRIDNS 205.171.3.25					    Feb 14 13:57:10					  ppp					  
  [wan]   SECDNS 205.171.2.25					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: SendConfigReq #3					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 174.xx.xx.xx					    Feb 14 13:57:10					  ppp					  
  [wan]   PRIDNS 205.171.3.25					    Feb 14 13:57:10					  ppp					  
  [wan]   SECDNS 205.171.2.25					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)					    Feb 14 13:57:10					  ppp					  
  [wan]   IPADDR 174.xx.xx.xx					    Feb 14 13:57:10					  ppp					  
  [wan]   PRIDNS 205.171.3.25					    Feb 14 13:57:10					  ppp					  
  [wan]   SECDNS 205.171.2.25					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: state change Ack-Sent --> Opened					    Feb 14 13:57:10					  ppp					  
  [wan] IPCP: LayerUp					    Feb 14 13:57:10					  ppp					  
  [wan]   174.xx.xx.xx -> 63.231.xx.xx					    Feb 14 13:57:11					  ppp					  
  [wan] IFACE: Up event					    Feb 14 13:57:11					  ppp					  
  [wan] IFACE: Rename interface ng0 to pppoe0

                                Triggering snowflakes one by one..
                                Intel(R) Core(TM) i5-4590T CPU @ 2.00GHz on an M400 WG box.

                                1 Reply Last reply Reply Quote 0
                                • R
                                  Rob Beckers
                                  last edited by

                                  Adam,

                                  Sorry for the delay, yesterday was a crazy day!
                                  The box that Storm put in is not a switch at all (that's what the guys called that installed it), it's a router that can do PPPoE. The brand is MikroTIK, type is 750UP. I suppose they have it set up in pass-through, so packets are just passed along. It does solve the problem though.

                                  -Rob-

                                  1 Reply Last reply Reply Quote 0
                                  • First post
                                    Last post
                                  Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.