DSL connection issues
-
We are experiencing an intermittent problem with our failover, DSL circuit. DSL router is in bridge mode, pfSense passes authentication information to at&t. at&t seems to think it's the firewall. I believe the username/password is being rejected for some reason. What is typical for a PPPoE connection with regards to authentication? It should authenticate once, then not need to until the session is dropped and reinitiated, right?
Is there anything on the firewall, in PPPoE configuration, that can cause this behavior? Below are logs of when it tries to connect and then finally successfully connects. To get it to work I typically cycle the DSL router a couple of times while disabling and enabling the PPPoE interface.
Jul 28 16:50:07 ppp: [opt4] IFACE: Rename interface ng0 to pppoe0
Jul 28 16:50:07 ppp: [opt4] IFACE: Up event
Jul 28 16:50:06 ppp: [opt4] 108.274.218.130 -> 67.38.70.59
Jul 28 16:50:06 ppp: [opt4] IPCP: LayerUp
Jul 28 16:50:06 ppp: [opt4] IPCP: state change Ack-Sent –> Opened
Jul 28 16:50:06 ppp: [opt4] SECDNS 68.94.157.1
Jul 28 16:50:06 ppp: [opt4] PRIDNS 68.94.156.1
Jul 28 16:50:06 ppp: [opt4] IPADDR 108.274.218.130
Jul 28 16:50:06 ppp: [opt4] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Jul 28 16:50:06 ppp: [opt4] SECDNS 68.94.157.1
Jul 28 16:50:06 ppp: [opt4] PRIDNS 68.94.156.1
Jul 28 16:50:06 ppp: [opt4] IPADDR 108.274.218.130
Jul 28 16:50:06 ppp: [opt4] IPCP: SendConfigReq #3
Jul 28 16:50:06 ppp: [opt4] SECDNS 68.94.157.1
Jul 28 16:50:06 ppp: [opt4] PRIDNS 68.94.156.1
Jul 28 16:50:06 ppp: [opt4] 108.274.218.130 is OK
Jul 28 16:50:06 ppp: [opt4] IPADDR 108.274.218.130
Jul 28 16:50:06 ppp: [opt4] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Jul 28 16:50:06 ppp: [opt4] IPV6CP: LayerFinish
Jul 28 16:50:06 ppp: [opt4] IPV6CP: state change Req-Sent –> Stopped
Jul 28 16:50:06 ppp: [opt4] IPV6CP: protocol was rejected by peer
Jul 28 16:50:06 ppp: [opt4_link0] LCP: protocol IPV6CP was rejected
Jul 28 16:50:06 ppp: [opt4_link0] LCP: rec'd Protocol Reject #59 (Opened)
Jul 28 16:50:06 ppp: [opt4] SECDNS 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] PRIDNS 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] IPADDR 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] IPCP: SendConfigReq #2
Jul 28 16:50:06 ppp: [opt4] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 28 16:50:06 ppp: [opt4] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 28 16:50:06 ppp: [opt4] IPCP: state change Req-Sent –> Ack-Sent
Jul 28 16:50:06 ppp: [opt4] IPADDR 67.38.70.59
Jul 28 16:50:06 ppp: [opt4] IPCP: SendConfigAck #217
Jul 28 16:50:06 ppp: [opt4] 67.38.70.59 is OK
Jul 28 16:50:06 ppp: [opt4] IPADDR 67.38.70.59
Jul 28 16:50:06 ppp: [opt4] IPCP: rec'd Configure Request #217 (Req-Sent)
Jul 28 16:50:06 ppp: [opt4] IPV6CP: SendConfigReq #1
Jul 28 16:50:06 ppp: [opt4] IPV6CP: state change Starting –> Req-Sent
Jul 28 16:50:06 ppp: [opt4] IPV6CP: Up event
Jul 28 16:50:06 ppp: [opt4] SECDNS 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] PRIDNS 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jul 28 16:50:06 ppp: [opt4] IPADDR 0.0.0.0
Jul 28 16:50:06 ppp: [opt4] IPCP: SendConfigReq #1
Jul 28 16:50:06 ppp: [opt4] IPCP: state change Starting –> Req-Sent
Jul 28 16:50:06 ppp: [opt4] IPCP: Up event
Jul 28 16:50:06 ppp: [opt4] IPV6CP: LayerStart
Jul 28 16:50:06 ppp: [opt4] IPV6CP: state change Initial –> Starting
Jul 28 16:50:06 ppp: [opt4] IPV6CP: Open event
Jul 28 16:50:06 ppp: [opt4] IPCP: LayerStart
Jul 28 16:50:06 ppp: [opt4] IPCP: state change Initial –> Starting
Jul 28 16:50:06 ppp: [opt4] IPCP: Open event
Jul 28 16:50:06 ppp: [opt4] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jul 28 16:50:06 ppp: [opt4_link0] Link: Join bundle "opt4"
Jul 28 16:50:06 ppp: [opt4_link0] Link: Matched action 'bundle "opt4" ""'
Jul 28 16:50:06 ppp: [opt4_link0] LCP: authorization successful
Jul 28 16:50:06 ppp: [opt4_link0] PAP: rec'd ACK #1 len: 5
Jul 28 16:50:06 ppp: [opt4_link0] LCP: LayerUp
Jul 28 16:50:06 ppp: [opt4_link0] PAP: sending REQUEST #1 len: 43
Jul 28 16:50:06 ppp: [opt4_link0] PAP: using authname "allstatefastener@static.att.net"
Jul 28 16:50:06 ppp: [opt4_link0] LCP: auth: peer wants PAP, I want nothing
Jul 28 16:50:06 ppp: [opt4_link0] LCP: state change Ack-Sent –> Opened
Jul 28 16:50:06 ppp: [opt4_link0] MAGICNUM fb7eeb88
Jul 28 16:50:06 ppp: [opt4_link0] MRU 1492
Jul 28 16:50:06 ppp: [opt4_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Jul 28 16:50:06 ppp: [opt4_link0] MAGICNUM fb7eeb88
Jul 28 16:50:06 ppp: [opt4_link0] MRU 1492
Jul 28 16:50:06 ppp: [opt4_link0] LCP: SendConfigReq #2
Jul 28 16:50:06 ppp: [opt4_link0] PROTOCOMP
Jul 28 16:50:06 ppp: [opt4_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Jul 28 16:50:06 ppp: [opt4_link0] LCP: state change Req-Sent –> Ack-Sent
Jul 28 16:50:06 ppp: [opt4_link0] MAGICNUM 5ab89d58
Jul 28 16:50:06 ppp: [opt4_link0] AUTHPROTO PAP
Jul 28 16:50:06 ppp: [opt4_link0] MRU 1492
Jul 28 16:50:06 ppp: [opt4_link0] LCP: SendConfigAck #58
Jul 28 16:50:06 ppp: [opt4_link0] MAGICNUM 5ab89d58
Jul 28 16:50:06 ppp: [opt4_link0] AUTHPROTO PAP
Jul 28 16:50:06 ppp: [opt4_link0] MRU 1492
Jul 28 16:50:06 ppp: [opt4_link0] LCP: rec'd Configure Request #58 (Req-Sent)
Jul 28 16:50:06 ppp: [opt4_link0] MAGICNUM fb7eeb88
Jul 28 16:50:06 ppp: [opt4_link0] MRU 1492
Jul 28 16:50:06 ppp: [opt4_link0] PROTOCOMP
Jul 28 16:50:06 ppp: [opt4_link0] LCP: SendConfigReq #1
Jul 28 16:50:06 ppp: [opt4_link0] LCP: state change Starting –> Req-Sent
Jul 28 16:50:06 ppp: [opt4_link0] LCP: Up event
Jul 28 16:50:06 ppp: [opt4_link0] Link: UP event
Jul 28 16:50:06 ppp: [opt4_link0] PPPoE: connection successful
Jul 28 16:50:06 ppp: PPPoE: rec'd ACNAME "se3.sfldmi-8Y044010602836"
Jul 28 16:50:04 ppp: [opt4_link0] PPPoE: Connecting to ''
Jul 28 16:50:04 ppp: [opt4_link0] Link: reconnection attempt 1
Jul 28 16:50:03 ppp: [opt4_link0] Link: reconnection attempt 1 in 1 seconds
Jul 28 16:50:03 ppp: [opt4_link0] LCP: Down event
Jul 28 16:50:03 ppp: [opt4_link0] Link: DOWN event
Jul 28 16:50:03 ppp: [opt4_link0] PPPoE connection timeout after 9 seconds
Jul 28 16:49:54 ppp: PPPoE: rec'd ACNAME "se3.sfldmi-8Y044010602836"
Jul 28 16:49:54 ppp: [opt4_link0] PPPoE: Connecting to ''
Jul 28 16:49:54 ppp: [opt4_link0] LCP: LayerStart
Jul 28 16:49:54 ppp: [opt4_link0] LCP: state change Initial –> Starting
Jul 28 16:49:54 ppp: [opt4_link0] LCP: Open event
Jul 28 16:49:54 ppp: [opt4_link0] Link: OPEN event
Jul 28 16:49:54 ppp: [opt4] Bundle: Interface ng0 created
Jul 28 16:49:54 ppp: web: web is not running
Jul 28 16:49:54 ppp: process 60712 started, version 5.6 (root@snapshots-8_3-i386.builders.pfsense.org 10:16 24-Jul-2013)
Jul 28 16:49:54 ppp:
Jul 28 16:49:54 ppp: Multi-link PPP daemon for FreeBSD
Jul 28 16:49:40 ppp: process 93792 terminated
Jul 28 16:49:40 ppp: [opt4_link0] Link: Shutdown
Jul 28 16:49:40 ppp: [opt4] Bundle: Shutdown
Jul 28 16:49:39 ppp: [opt4_link0] LCP: LayerFinish
Jul 28 16:49:39 ppp: [opt4_link0] LCP: state change Starting –> Initial
Jul 28 16:49:39 ppp: [opt4_link0] LCP: Close event
Jul 28 16:49:38 ppp: [opt4] IPV6CP: Close event
Jul 28 16:49:38 ppp: [opt4] IPCP: Close event
Jul 28 16:49:38 ppp: [opt4] IFACE: Close event
Jul 28 16:49:38 ppp: caught fatal signal term
Jul 28 16:49:36 ppp: [opt4_link0] Link: reconnection attempt 14 in 3 seconds
Jul 28 16:49:36 ppp: [opt4_link0] LCP: Down event
Jul 28 16:49:36 ppp: [opt4_link0] Link: DOWN event
Jul 28 16:49:36 ppp: [opt4_link0] PPPoE connection timeout after 9 seconds
Jul 28 16:49:27 ppp: PPPoE: rec'd ACNAME "se3.sfldmi-8Y044010602836"
Jul 28 16:49:27 ppp: [opt4_link0] PPPoE: Connecting to ''
Jul 28 16:49:27 ppp: [opt4_link0] Link: reconnection attempt 13
Jul 28 16:49:23 ppp: [opt4_link0] Link: reconnection attempt 13 in 4 seconds