5. PPPoE: Occasional disconnect; CHAP response failure; reboot needed.

PPPoE: Occasional disconnect; CHAP response failure; reboot needed.

  • A

    Been using pfsense for a year now. Great, great system, apart from this one issue which has happened on 2.01 and 2.1.

    I am on VDSL in the UK on a 80/20 link. Generally, the connection is solid as a rock but occasionally drops (say once a month). Occasionally, the system will not reconnect and the only method I have found to reconnect is by rebooting the box (there may be others, but it's the quickest when it is in this state). When it does happen, the PPP connection doesn't reconnect giving the following pattern in the log files…

    link down, link down... link down, link up, reconnection attempt, get to sending CHAP authname and then sending response times out.

    A good link connection is characterised by this sort of behaviour (I think I have altered everything that can trace IPs/accounts)

    Jan  7 01:16:05 edge ppp: [wan_link0] LCP: rec'd Terminate Request #3 (Opened)
Jan  7 01:16:05 edge ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan  7 01:16:05 edge ppp: [wan_link0] Link: Leave bundle "wan"
Jan  7 01:16:05 edge ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan  7 01:16:05 edge ppp: [wan] IPCP: Close event
Jan  7 01:16:05 edge ppp: [wan] IPCP: state change Opened --> Closing
Jan  7 01:16:05 edge ppp: [wan] IPCP: SendTerminateReq #4
Jan  7 01:16:05 edge ppp: [wan] IPCP: LayerDown
Jan  7 01:16:05 edge ppp: [wan] IFACE: Down event
Jan  7 01:16:05 edge ppp: [wan] IFACE: Rename interface pppoe1 to pppoe1
Jan  7 01:16:05 edge ppp: [wan] IPV6CP: Close event
Jan  7 01:16:05 edge ppp: [wan] IPV6CP: state change Stopped --> Closed
Jan  7 01:16:05 edge ppp: [wan] IPCP: Down event
Jan  7 01:16:05 edge ppp: [wan] IPCP: LayerFinish
Jan  7 01:16:05 edge ppp: [wan] Bundle: No NCPs left. Closing links...
Jan  7 01:16:05 edge ppp: [wan] IPCP: state change Closing --> Initial
Jan  7 01:16:05 edge ppp: [wan] IPV6CP: Down event
Jan  7 01:16:05 edge ppp: [wan] IPV6CP: state change Closed --> Initial
Jan  7 01:16:05 edge ppp: [wan_link0] LCP: SendTerminateAck #10
Jan  7 01:16:05 edge ppp: [wan_link0] LCP: LayerDown
Jan  7 01:16:07 edge ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan  7 01:16:07 edge ppp: [wan_link0] LCP: LayerFinish
Jan  7 01:16:07 edge ppp: [wan_link0] PPPoE: connection closed
Jan  7 01:16:07 edge ppp: [wan_link0] Link: DOWN event
Jan  7 01:16:07 edge ppp: [wan_link0] LCP: Down event
Jan  7 01:16:07 edge ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan  7 01:16:07 edge ppp: [wan_link0] LCP: LayerStart
Jan  7 01:16:07 edge ppp: [wan_link0] Link: reconnection attempt 1 in 3 seconds
Jan  7 01:16:10 edge ppp: [wan_link0] Link: reconnection attempt 1
Jan  7 01:16:10 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  7 01:16:10 edge ppp: PPPoE: rec'd ACNAME "bras-red5.mqd-B222E320705498"
Jan  7 01:16:10 edge ppp: [wan_link0] PPPoE: connection successful
Jan  7 01:16:10 edge ppp: [wan_link0] Link: UP event
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: Up event
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #11
Jan  7 01:16:10 edge ppp: [wan_link0]   PROTOCOMP
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Request #25 (Req-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 4d459273
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigAck #25
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 4d459273
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Reject #11 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   PROTOCOMP
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #12
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Ack #12 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: LayerUp
Jan  7 01:16:10 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 34
Jan  7 01:16:10 edge ppp: [wan_link0]   Name: "bras-red5.mqd"
Jan  7 01:16:10 edge ppp: [wan_link0] CHAP: Using authname "***************"
Jan  7 01:16:10 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Request #1 (Opened)
Jan  7 01:16:10 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 51f7671f
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: LayerDown
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #13
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigAck #1
Jan  7 01:16:10 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 51f7671f
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: state change Opened --> Ack-Sent
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Nak #13 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1500
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #14
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Nak #14 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1500
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #15
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Nak #15 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1500
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #16
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: rec'd Configure Nak #16 (Ack-Sent)
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1500
Jan  7 01:16:10 edge ppp: [wan_link0] LCP: SendConfigReq #17
Jan  7 01:16:10 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:10 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: rec'd Configure Nak #17 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan_link0]   MRU 1500
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: SendConfigReq #18
Jan  7 01:16:11 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:11 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: rec'd Configure Reject #18 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan_link0]   MRU 1492
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: SendConfigReq #19
Jan  7 01:16:11 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: rec'd Configure Ack #19 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan_link0]   MAGICNUM 79ec5152
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: LayerUp
Jan  7 01:16:11 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #2 len: 28
Jan  7 01:16:11 edge ppp: [wan_link0]   Name: "t6-bng1"
Jan  7 01:16:11 edge ppp: [wan_link0] CHAP: Using authname "*****************"
Jan  7 01:16:11 edge ppp: [wan_link0] CHAP: sending RESPONSE #2 len: 52
Jan  7 01:16:11 edge ppp: [wan_link0] CHAP: rec'd SUCCESS #2 len: 4
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: authorization successful
Jan  7 01:16:11 edge ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
Jan  7 01:16:11 edge ppp: [wan_link0] Link: Join bundle "wan"
Jan  7 01:16:11 edge ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jan  7 01:16:11 edge ppp: [wan] IPCP: Open event
Jan  7 01:16:11 edge ppp: [wan] IPCP: state change Initial --> Starting
Jan  7 01:16:11 edge ppp: [wan] IPCP: LayerStart
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: Open event
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: state change Initial --> Starting
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: LayerStart
Jan  7 01:16:11 edge ppp: [wan] IPCP: Up event
Jan  7 01:16:11 edge ppp: [wan] IPCP: state change Starting --> Req-Sent
Jan  7 01:16:11 edge ppp: [wan] IPCP: SendConfigReq #5
Jan  7 01:16:11 edge ppp: [wan]   IPADDR 0.0.0.0
Jan  7 01:16:11 edge ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: Up event
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: state change Starting --> Req-Sent
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: SendConfigReq #2
Jan  7 01:16:11 edge ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
Jan  7 01:16:11 edge ppp: [wan]   IPADDR A.B.C.D
Jan  7 01:16:11 edge ppp: [wan]     A.B.C.D is OK
Jan  7 01:16:11 edge ppp: [wan] IPCP: SendConfigAck #1
Jan  7 01:16:11 edge ppp: [wan]   IPADDR A.B.C.D
Jan  7 01:16:11 edge ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent
Jan  7 01:16:11 edge ppp: [wan] IPCP: rec'd Configure Reject #5 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan  7 01:16:11 edge ppp: [wan] IPCP: SendConfigReq #6
Jan  7 01:16:11 edge ppp: [wan]   IPADDR 0.0.0.0
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: rec'd Protocol Reject #2 (Opened)
Jan  7 01:16:11 edge ppp: [wan_link0] LCP: protocol IPV6CP was rejected
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: protocol was rejected by peer
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: state change Req-Sent --> Stopped
Jan  7 01:16:11 edge ppp: [wan] IPV6CP: LayerFinish
Jan  7 01:16:11 edge ppp: [wan] IPCP: rec'd Configure Nak #6 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan]   IPADDR E.F.G.H
Jan  7 01:16:11 edge ppp: [wan]     E.F.G.H is OK
Jan  7 01:16:11 edge ppp: [wan] IPCP: SendConfigReq #7
Jan  7 01:16:11 edge ppp: [wan]   IPADDR E.F.G.H
Jan  7 01:16:11 edge ppp: [wan] IPCP: rec'd Configure Ack #7 (Ack-Sent)
Jan  7 01:16:11 edge ppp: [wan]   IPADDR E.F.G.H
Jan  7 01:16:11 edge ppp: [wan] IPCP: state change Ack-Sent --> Opened
Jan  7 01:16:11 edge ppp: [wan] IPCP: LayerUp
Jan  7 01:16:11 edge ppp: [wan]   E.F.G.H -> A.B.C.D
Jan  7 01:16:11 edge ppp: [wan] IFACE: Up event
Jan  7 01:16:11 edge ppp: [wan] IFACE: Rename interface ng0 to pppoe1

    whilst a bad/cyclical disconnect/auth failure is:

    
Jan  9 00:07:08 edge ppp: [wan_link0] LCP: no reply to 1 echo request(s)
Jan  9 00:07:18 edge ppp: [wan_link0] LCP: no reply to 2 echo request(s)
Jan  9 00:07:28 edge ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Jan  9 00:07:38 edge ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Jan  9 00:07:45 edge ppp: [wan_link0] LCP: rec'd Terminate Request #26 (Opened)
Jan  9 00:07:45 edge ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan  9 00:07:45 edge ppp: [wan_link0] Link: Leave bundle "wan"
Jan  9 00:07:45 edge ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan  9 00:07:45 edge ppp: [wan] IPCP: Close event
Jan  9 00:07:45 edge ppp: [wan] IPCP: state change Opened --> Closing
Jan  9 00:07:45 edge ppp: [wan] IPCP: SendTerminateReq #8
Jan  9 00:07:45 edge ppp: [wan] IPCP: LayerDown
Jan  9 00:07:45 edge ppp: [wan] IFACE: Down event
Jan  9 00:07:45 edge ppp: [wan] IFACE: Rename interface pppoe1 to pppoe1
Jan  9 00:07:45 edge ppp: [wan] IPV6CP: Close event
Jan  9 00:07:45 edge ppp: [wan] IPV6CP: state change Stopped --> Closed
Jan  9 00:07:45 edge ppp: [wan] IPCP: Down event
Jan  9 00:07:45 edge ppp: [wan] IPCP: LayerFinish
Jan  9 00:07:45 edge ppp: [wan] Bundle: No NCPs left. Closing links...
Jan  9 00:07:45 edge ppp: [wan] IPCP: state change Closing --> Initial
Jan  9 00:07:45 edge ppp: [wan] IPV6CP: Down event
Jan  9 00:07:45 edge ppp: [wan] IPV6CP: state change Closed --> Initial
Jan  9 00:07:45 edge ppp: [wan_link0] LCP: SendTerminateAck #20
Jan  9 00:07:45 edge ppp: [wan_link0] LCP: LayerDown
Jan  9 00:07:47 edge ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan  9 00:07:47 edge ppp: [wan_link0] LCP: LayerFinish
Jan  9 00:07:47 edge ppp: [wan_link0] PPPoE: connection closed
Jan  9 00:07:47 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:07:47 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:07:47 edge ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan  9 00:07:47 edge ppp: [wan_link0] LCP: LayerStart
Jan  9 00:07:47 edge ppp: [wan_link0] Link: reconnection attempt 1 in 2 seconds
Jan  9 00:07:49 edge ppp: [wan_link0] Link: reconnection attempt 1
Jan  9 00:07:49 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:07:58 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:07:58 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:07:58 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:07:58 edge ppp: [wan_link0] Link: reconnection attempt 2 in 1 seconds
Jan  9 00:07:59 edge ppp: [wan_link0] Link: reconnection attempt 2
Jan  9 00:07:59 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:08:08 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:08:08 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:08:08 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:08:08 edge ppp: [wan_link0] Link: reconnection attempt 3 in 1 seconds
Jan  9 00:08:09 edge ppp: [wan_link0] Link: reconnection attempt 3
Jan  9 00:08:09 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:08:18 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:08:18 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:08:18 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:08:18 edge ppp: [wan_link0] Link: reconnection attempt 4 in 3 seconds
Jan  9 00:08:21 edge ppp: [wan_link0] Link: reconnection attempt 4
Jan  9 00:08:21 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:08:30 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:08:30 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:08:30 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:08:30 edge ppp: [wan_link0] Link: reconnection attempt 5 in 1 seconds
Jan  9 00:08:31 edge ppp: [wan_link0] Link: reconnection attempt 5
Jan  9 00:08:31 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:08:40 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:08:40 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:08:40 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:08:40 edge ppp: [wan_link0] Link: reconnection attempt 6 in 4 seconds
Jan  9 00:08:44 edge ppp: [wan_link0] Link: reconnection attempt 6
Jan  9 00:08:44 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:08:53 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:08:53 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:08:53 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:08:53 edge ppp: [wan_link0] Link: reconnection attempt 7 in 4 seconds
Jan  9 00:08:57 edge ppp: [wan_link0] Link: reconnection attempt 7
Jan  9 00:08:57 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:09:06 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:09:06 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:09:06 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:09:06 edge ppp: [wan_link0] Link: reconnection attempt 8 in 4 seconds
Jan  9 00:09:10 edge ppp: [wan_link0] Link: reconnection attempt 8
Jan  9 00:09:10 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:09:19 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:09:19 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:09:19 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:09:19 edge ppp: [wan_link0] Link: reconnection attempt 9 in 1 seconds
Jan  9 00:09:20 edge ppp: [wan_link0] Link: reconnection attempt 9
Jan  9 00:09:20 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:09:29 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:09:29 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:09:29 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:09:29 edge ppp: [wan_link0] Link: reconnection attempt 10 in 4 seconds
Jan  9 00:09:33 edge ppp: [wan_link0] Link: reconnection attempt 10
Jan  9 00:09:33 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:09:42 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:09:42 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:09:42 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:09:42 edge ppp: [wan_link0] Link: reconnection attempt 11 in 3 seconds
Jan  9 00:09:45 edge ppp: [wan_link0] Link: reconnection attempt 11
Jan  9 00:09:45 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:09:54 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:09:54 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:09:54 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:09:54 edge ppp: [wan_link0] Link: reconnection attempt 12 in 4 seconds
Jan  9 00:09:58 edge ppp: [wan_link0] Link: reconnection attempt 12
Jan  9 00:09:58 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:10:07 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:10:07 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:10:07 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:10:07 edge ppp: [wan_link0] Link: reconnection attempt 13 in 3 seconds
Jan  9 00:10:11 edge ppp: [wan_link0] Link: reconnection attempt 13
Jan  9 00:10:11 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:10:20 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:10:20 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:10:20 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:10:20 edge ppp: [wan_link0] Link: reconnection attempt 14 in 4 seconds
Jan  9 00:10:24 edge ppp: [wan_link0] Link: reconnection attempt 14
Jan  9 00:10:24 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:10:33 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:10:33 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:10:33 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:10:33 edge ppp: [wan_link0] Link: reconnection attempt 15 in 1 seconds
Jan  9 00:10:34 edge ppp: [wan_link0] Link: reconnection attempt 15
Jan  9 00:10:34 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:10:43 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:10:43 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:10:43 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:10:43 edge ppp: [wan_link0] Link: reconnection attempt 16 in 1 seconds
Jan  9 00:10:44 edge ppp: [wan_link0] Link: reconnection attempt 16
Jan  9 00:10:44 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:10:53 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:10:53 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:10:53 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:10:53 edge ppp: [wan_link0] Link: reconnection attempt 17 in 3 seconds
Jan  9 00:10:56 edge ppp: [wan_link0] Link: reconnection attempt 17
Jan  9 00:10:56 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:11:05 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:11:05 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:11:05 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:11:05 edge ppp: [wan_link0] Link: reconnection attempt 18 in 4 seconds
Jan  9 00:11:09 edge ppp: [wan_link0] Link: reconnection attempt 18
Jan  9 00:11:09 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:11:18 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:11:18 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:11:18 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:11:18 edge ppp: [wan_link0] Link: reconnection attempt 19 in 1 seconds
Jan  9 00:11:19 edge ppp: [wan_link0] Link: reconnection attempt 19
Jan  9 00:11:19 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:11:28 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:11:28 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:11:28 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:11:28 edge ppp: [wan_link0] Link: reconnection attempt 20 in 1 seconds
Jan  9 00:11:29 edge ppp: [wan_link0] Link: reconnection attempt 20
Jan  9 00:11:29 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:11:38 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:11:38 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:11:38 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:11:38 edge ppp: [wan_link0] Link: reconnection attempt 21 in 4 seconds
Jan  9 00:11:42 edge ppp: [wan_link0] Link: reconnection attempt 21
Jan  9 00:11:42 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:11:51 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:11:51 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:11:51 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:11:51 edge ppp: [wan_link0] Link: reconnection attempt 22 in 2 seconds
Jan  9 00:11:53 edge ppp: [wan_link0] Link: reconnection attempt 22
Jan  9 00:11:53 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:12:02 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:12:02 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:12:02 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:12:02 edge ppp: [wan_link0] Link: reconnection attempt 23 in 1 seconds
Jan  9 00:12:03 edge ppp: [wan_link0] Link: reconnection attempt 23
Jan  9 00:12:03 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:12:12 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:12:12 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:12:12 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:12:12 edge ppp: [wan_link0] Link: reconnection attempt 24 in 3 seconds
Jan  9 00:12:15 edge ppp: [wan_link0] Link: reconnection attempt 24
Jan  9 00:12:15 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:12:24 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:12:24 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:12:24 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:12:24 edge ppp: [wan_link0] Link: reconnection attempt 25 in 2 seconds
Jan  9 00:12:26 edge ppp: [wan_link0] Link: reconnection attempt 25
Jan  9 00:12:26 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:12:28 edge ppp: PPPoE: rec'd ACNAME "bras-red5.mqd-B222E320705498"
Jan  9 00:12:29 edge ppp: [wan_link0] PPPoE: connection successful
Jan  9 00:12:29 edge ppp: [wan_link0] Link: UP event
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: Up event
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: SendConfigReq #21
Jan  9 00:12:29 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:12:29 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:12:29 edge ppp: [wan_link0]   MAGICNUM 897c22dc
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: rec'd Configure Request #52 (Req-Sent)
Jan  9 00:12:29 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:12:29 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:12:29 edge ppp: [wan_link0]   MAGICNUM 6e10a0f3
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: SendConfigAck #52
Jan  9 00:12:29 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:12:29 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:12:29 edge ppp: [wan_link0]   MAGICNUM 6e10a0f3
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: rec'd Configure Reject #21 (Ack-Sent)
Jan  9 00:12:29 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: SendConfigReq #22
Jan  9 00:12:29 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:12:29 edge ppp: [wan_link0]   MAGICNUM 897c22dc
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: rec'd Configure Ack #22 (Ack-Sent)
Jan  9 00:12:29 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:12:29 edge ppp: [wan_link0]   MAGICNUM 897c22dc
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  9 00:12:29 edge ppp: [wan_link0] LCP: LayerUp
Jan  9 00:12:29 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 34
Jan  9 00:12:29 edge ppp: [wan_link0]   Name: "bras-red5.mqd"
Jan  9 00:12:29 edge ppp: [wan_link0] CHAP: Using authname "*********************"
Jan  9 00:12:29 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:31 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:33 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:35 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:37 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:39 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:41 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:43 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:45 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:47 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:49 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:51 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:53 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:55 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:57 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:12:59 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:01 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:03 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:05 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:07 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: authorization timer expired
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: authorization failed
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: parameter negotiation failed
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: SendTerminateReq #23
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: LayerDown
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: rec'd Terminate Ack #23 (Stopping)
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: LayerFinish
Jan  9 00:13:09 edge ppp: [wan_link0] PPPoE: connection closed
Jan  9 00:13:09 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan  9 00:13:09 edge ppp: [wan_link0] LCP: LayerStart
Jan  9 00:13:09 edge ppp: [wan_link0] Link: reconnection attempt 26 in 2 seconds
Jan  9 00:13:11 edge ppp: [wan_link0] Link: reconnection attempt 26
Jan  9 00:13:11 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:13:20 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:13:20 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:13:20 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:13:20 edge ppp: [wan_link0] Link: reconnection attempt 27 in 4 seconds
Jan  9 00:13:24 edge ppp: [wan_link0] Link: reconnection attempt 27
Jan  9 00:13:24 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:13:33 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:13:33 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:13:33 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:13:33 edge ppp: [wan_link0] Link: reconnection attempt 28 in 2 seconds
Jan  9 00:13:35 edge ppp: [wan_link0] Link: reconnection attempt 28
Jan  9 00:13:35 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:13:44 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:13:44 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:13:44 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:13:44 edge ppp: [wan_link0] Link: reconnection attempt 29 in 1 seconds
Jan  9 00:13:45 edge ppp: [wan_link0] Link: reconnection attempt 29
Jan  9 00:13:45 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:13:45 edge ppp: PPPoE: rec'd ACNAME "bras-red5.mqd-B222E320705498"
Jan  9 00:13:46 edge ppp: [wan_link0] PPPoE: connection successful
Jan  9 00:13:46 edge ppp: [wan_link0] Link: UP event
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: Up event
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: SendConfigReq #24
Jan  9 00:13:46 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:13:46 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:13:46 edge ppp: [wan_link0]   MAGICNUM b0dd6e64
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: rec'd Configure Request #139 (Req-Sent)
Jan  9 00:13:46 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:13:46 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:13:46 edge ppp: [wan_link0]   MAGICNUM 7d1a62ba
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: SendConfigAck #139
Jan  9 00:13:46 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:13:46 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:13:46 edge ppp: [wan_link0]   MAGICNUM 7d1a62ba
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: rec'd Configure Reject #24 (Ack-Sent)
Jan  9 00:13:46 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: SendConfigReq #25
Jan  9 00:13:46 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:13:46 edge ppp: [wan_link0]   MAGICNUM b0dd6e64
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: rec'd Configure Ack #25 (Ack-Sent)
Jan  9 00:13:46 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:13:46 edge ppp: [wan_link0]   MAGICNUM b0dd6e64
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  9 00:13:46 edge ppp: [wan_link0] LCP: LayerUp
Jan  9 00:13:46 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 34
Jan  9 00:13:46 edge ppp: [wan_link0]   Name: "bras-red5.mqd"
Jan  9 00:13:46 edge ppp: [wan_link0] CHAP: Using authname "*****************"
Jan  9 00:13:46 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:48 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:50 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:53 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:55 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:57 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:13:59 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:01 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:03 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:05 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:07 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:09 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:11 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:13 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:15 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:17 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:19 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:21 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:23 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:25 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: authorization timer expired
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: authorization failed
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: parameter negotiation failed
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: SendTerminateReq #26
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: LayerDown
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: rec'd Terminate Ack #26 (Stopping)
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: LayerFinish
Jan  9 00:14:27 edge ppp: [wan_link0] PPPoE: connection closed
Jan  9 00:14:27 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan  9 00:14:27 edge ppp: [wan_link0] LCP: LayerStart
Jan  9 00:14:27 edge ppp: [wan_link0] Link: reconnection attempt 30 in 2 seconds
Jan  9 00:14:29 edge ppp: [wan_link0] Link: reconnection attempt 30
Jan  9 00:14:29 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:14:38 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:14:38 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:14:38 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:14:38 edge ppp: [wan_link0] Link: reconnection attempt 31 in 3 seconds
Jan  9 00:14:41 edge ppp: [wan_link0] Link: reconnection attempt 31
Jan  9 00:14:41 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:14:50 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:14:50 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:14:50 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:14:50 edge ppp: [wan_link0] Link: reconnection attempt 32 in 1 seconds
Jan  9 00:14:51 edge ppp: [wan_link0] Link: reconnection attempt 32
Jan  9 00:14:51 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:00 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:00 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:00 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:00 edge ppp: [wan_link0] Link: reconnection attempt 33 in 1 seconds
Jan  9 00:15:01 edge ppp: [wan_link0] Link: reconnection attempt 33
Jan  9 00:15:01 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:10 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:10 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:10 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:10 edge ppp: [wan_link0] Link: reconnection attempt 34 in 2 seconds
Jan  9 00:15:12 edge ppp: [wan_link0] Link: reconnection attempt 34
Jan  9 00:15:12 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:21 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:21 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:21 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:21 edge ppp: [wan_link0] Link: reconnection attempt 35 in 1 seconds
Jan  9 00:15:22 edge ppp: [wan_link0] Link: reconnection attempt 35
Jan  9 00:15:22 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:31 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:31 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:31 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:31 edge ppp: [wan_link0] Link: reconnection attempt 36 in 4 seconds
Jan  9 00:15:35 edge ppp: [wan_link0] Link: reconnection attempt 36
Jan  9 00:15:35 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:44 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:44 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:44 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:44 edge ppp: [wan_link0] Link: reconnection attempt 37 in 4 seconds
Jan  9 00:15:48 edge ppp: [wan_link0] Link: reconnection attempt 37
Jan  9 00:15:48 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:15:57 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:15:57 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:15:57 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:15:57 edge ppp: [wan_link0] Link: reconnection attempt 38 in 3 seconds
Jan  9 00:16:00 edge ppp: [wan_link0] Link: reconnection attempt 38
Jan  9 00:16:00 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:16:09 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:16:09 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:16:09 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:16:09 edge ppp: [wan_link0] Link: reconnection attempt 39 in 1 seconds
Jan  9 00:16:10 edge ppp: [wan_link0] Link: reconnection attempt 39
Jan  9 00:16:10 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:16:19 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:16:19 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:16:19 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:16:19 edge ppp: [wan_link0] Link: reconnection attempt 40 in 3 seconds
Jan  9 00:16:22 edge ppp: [wan_link0] Link: reconnection attempt 40
Jan  9 00:16:22 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:16:31 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:16:31 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:16:31 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:16:31 edge ppp: [wan_link0] Link: reconnection attempt 41 in 1 seconds
Jan  9 00:16:32 edge ppp: [wan_link0] Link: reconnection attempt 41
Jan  9 00:16:32 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:16:32 edge ppp: PPPoE: rec'd ACNAME "bras-red5.mqd-B222E320705498"
Jan  9 00:16:33 edge ppp: [wan_link0] PPPoE: connection successful
Jan  9 00:16:33 edge ppp: [wan_link0] Link: UP event
Jan  9 00:16:33 edge ppp: [wan_link0] LCP: Up event
Jan  9 00:16:33 edge ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Jan  9 00:16:33 edge ppp: [wan_link0] LCP: SendConfigReq #27
Jan  9 00:16:33 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:16:33 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:33 edge ppp: [wan_link0]   MAGICNUM 76a1ba16
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: SendConfigReq #28
Jan  9 00:16:35 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:16:35 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:35 edge ppp: [wan_link0]   MAGICNUM 76a1ba16
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: rec'd Configure Request #233 (Req-Sent)
Jan  9 00:16:35 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:35 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:16:35 edge ppp: [wan_link0]   MAGICNUM 05bc0d3b
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: SendConfigAck #233
Jan  9 00:16:35 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:35 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:16:35 edge ppp: [wan_link0]   MAGICNUM 05bc0d3b
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: rec'd Configure Reject #28 (Ack-Sent)
Jan  9 00:16:35 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: SendConfigReq #29
Jan  9 00:16:35 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:35 edge ppp: [wan_link0]   MAGICNUM 76a1ba16
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: rec'd Configure Ack #29 (Ack-Sent)
Jan  9 00:16:35 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:16:35 edge ppp: [wan_link0]   MAGICNUM 76a1ba16
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  9 00:16:35 edge ppp: [wan_link0] LCP: LayerUp
Jan  9 00:16:35 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 34
Jan  9 00:16:35 edge ppp: [wan_link0]   Name: "bras-red5.mqd"
Jan  9 00:16:35 edge ppp: [wan_link0] CHAP: Using authname "********************"
Jan  9 00:16:35 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:37 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:39 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:41 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:43 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:45 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:47 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:49 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:51 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:53 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:55 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:57 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:59 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:17:01 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:17:03 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:17:05 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:17:07 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:17:09 edge ppp: [wan_link0] CHAP: rec'd FAILURE #1 len: 42
Jan  9 00:17:09 edge ppp: [wan_link0]   MESG: CHAP authentication failure, unit 3620
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: authorization failed
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: parameter negotiation failed
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: SendTerminateReq #30
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: LayerDown
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: rec'd Terminate Request #234 (Stopping)
Jan  9 00:17:09 edge ppp: [wan_link0] LCP: SendTerminateAck #31
Jan  9 00:17:10 edge ppp: [wan_link0] PPPoE: connection closed
Jan  9 00:17:10 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:17:10 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:17:10 edge ppp: [wan_link0] LCP: state change Stopping --> Starting
Jan  9 00:17:10 edge ppp: [wan_link0] Link: reconnection attempt 42 in 2 seconds
Jan  9 00:17:12 edge ppp: [wan_link0] Link: reconnection attempt 42
Jan  9 00:17:12 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:17:21 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:17:21 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:17:21 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:17:21 edge ppp: [wan_link0] Link: reconnection attempt 43 in 1 seconds
Jan  9 00:17:22 edge ppp: [wan_link0] Link: reconnection attempt 43
Jan  9 00:17:22 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:17:31 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:17:31 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:17:31 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:17:31 edge ppp: [wan_link0] Link: reconnection attempt 44 in 2 seconds
Jan  9 00:17:33 edge ppp: [wan_link0] Link: reconnection attempt 44
Jan  9 00:17:33 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:17:42 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:17:42 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:17:42 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:17:42 edge ppp: [wan_link0] Link: reconnection attempt 45 in 4 seconds
Jan  9 00:17:46 edge ppp: [wan_link0] Link: reconnection attempt 45
Jan  9 00:17:46 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:17:55 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:17:55 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:17:55 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:17:55 edge ppp: [wan_link0] Link: reconnection attempt 46 in 3 seconds
Jan  9 00:17:58 edge ppp: [wan_link0] Link: reconnection attempt 46
Jan  9 00:17:58 edge ppp: [wan_link0] PPPoE: Connecting to ''

    As you can see, I let this continue for over 10 minutes. Following a reboot I get a (fairly) clean connection

    
Jan  9 00:19:12 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:19:12 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:19:12 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:19:12 edge ppp: [wan_link0] Link: reconnection attempt 1 in 3 seconds
Jan  9 00:19:15 edge ppp: [wan_link0] Link: reconnection attempt 1
Jan  9 00:19:15 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:19:24 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:19:24 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:19:24 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:19:24 edge ppp: [wan_link0] Link: reconnection attempt 2 in 1 seconds
Jan  9 00:19:25 edge ppp: [wan_link0] Link: reconnection attempt 2
Jan  9 00:19:25 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:19:34 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:19:34 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:19:34 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:19:34 edge ppp: [wan_link0] Link: reconnection attempt 3 in 3 seconds
Jan  9 00:19:37 edge ppp: [wan_link0] Link: reconnection attempt 3
Jan  9 00:19:37 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:19:46 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:19:46 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:19:46 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:19:46 edge ppp: [wan_link0] Link: reconnection attempt 4 in 2 seconds
Jan  9 00:19:48 edge ppp: [wan_link0] Link: reconnection attempt 4
Jan  9 00:19:48 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:19:57 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:19:57 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:19:57 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:19:57 edge ppp: [wan_link0] Link: reconnection attempt 5 in 1 seconds
Jan  9 00:19:58 edge ppp: [wan_link0] Link: reconnection attempt 5
Jan  9 00:19:58 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:20:07 edge ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan  9 00:20:07 edge ppp: [wan_link0] Link: DOWN event
Jan  9 00:20:07 edge ppp: [wan_link0] LCP: Down event
Jan  9 00:20:07 edge ppp: [wan_link0] Link: reconnection attempt 6 in 2 seconds
Jan  9 00:20:09 edge ppp: [wan_link0] Link: reconnection attempt 6
Jan  9 00:20:09 edge ppp: [wan_link0] PPPoE: Connecting to ''
Jan  9 00:20:09 edge ppp: PPPoE: rec'd ACNAME "bras-red5.mqd-B222E320705498"
Jan  9 00:20:11 edge ppp: [wan_link0] PPPoE: connection successful
Jan  9 00:20:11 edge ppp: [wan_link0] Link: UP event
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: Up event
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: state change Starting --> Req-Sent
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: SendConfigReq #1
Jan  9 00:20:11 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:20:11 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:11 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: rec'd Configure Request #188 (Req-Sent)
Jan  9 00:20:11 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:11 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:20:11 edge ppp: [wan_link0]   MAGICNUM 10255e50
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: SendConfigAck #188
Jan  9 00:20:11 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:11 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:20:11 edge ppp: [wan_link0]   MAGICNUM 10255e50
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Jan  9 00:20:11 edge ppp: [wan_link0]   PROTOCOMP
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: SendConfigReq #2
Jan  9 00:20:11 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:11 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Jan  9 00:20:11 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:11 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  9 00:20:11 edge ppp: [wan_link0] LCP: LayerUp
Jan  9 00:20:11 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #1 len: 34
Jan  9 00:20:11 edge ppp: [wan_link0]   Name: "bras-red5.mqd"
Jan  9 00:20:11 edge ppp: [wan_link0] CHAP: Using authname "*******************"
Jan  9 00:20:11 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:13 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:15 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:17 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:19 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:21 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:23 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Request #2 (Opened)
Jan  9 00:20:23 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM 5c1ad887
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: LayerDown
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #3
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigAck #2
Jan  9 00:20:23 edge ppp: [wan_link0]   AUTHPROTO CHAP MD5
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM 5c1ad887
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: state change Opened --> Ack-Sent
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Nak #3 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1500
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #4
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Nak #4 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1500
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #5
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Nak #5 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1500
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #6
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Nak #6 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1500
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #7
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Nak #7 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1500
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #8
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Reject #8 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MRU 1492
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: SendConfigReq #9
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Configure Ack #9 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan_link0]   MAGICNUM adef5db6
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: state change Ack-Sent --> Opened
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: LayerUp
Jan  9 00:20:23 edge ppp: [wan_link0] CHAP: rec'd CHALLENGE #2 len: 28
Jan  9 00:20:23 edge ppp: [wan_link0]   Name: "t6-bng1"
Jan  9 00:20:23 edge ppp: [wan_link0] CHAP: Using authname "***************************"
Jan  9 00:20:23 edge ppp: [wan_link0] CHAP: sending RESPONSE #2 len: 52
Jan  9 00:20:23 edge ppp: [wan_link0] CHAP: rec'd SUCCESS #2 len: 4
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: authorization successful
Jan  9 00:20:23 edge ppp: [wan_link0] Link: Matched action 'bundle "wan" ""'
Jan  9 00:20:23 edge ppp: [wan_link0] Link: Join bundle "wan"
Jan  9 00:20:23 edge ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jan  9 00:20:23 edge ppp: [wan] IPCP: Open event
Jan  9 00:20:23 edge ppp: [wan] IPCP: state change Initial --> Starting
Jan  9 00:20:23 edge ppp: [wan] IPCP: LayerStart
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: Open event
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: state change Initial --> Starting
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: LayerStart
Jan  9 00:20:23 edge ppp: [wan] IPCP: Up event
Jan  9 00:20:23 edge ppp: [wan] IPCP: state change Starting --> Req-Sent
Jan  9 00:20:23 edge ppp: [wan] IPCP: SendConfigReq #1
Jan  9 00:20:23 edge ppp: [wan]   IPADDR 0.0.0.0
Jan  9 00:20:23 edge ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: Up event
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: state change Starting --> Req-Sent
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: SendConfigReq #1
Jan  9 00:20:23 edge ppp: [wan] IPCP: rec'd Configure Request #1 (Req-Sent)
Jan  9 00:20:23 edge ppp: [wan]   IPADDR A.B.C.D
Jan  9 00:20:23 edge ppp: [wan]     A.B.C.D is OK
Jan  9 00:20:23 edge ppp: [wan] IPCP: SendConfigAck #1
Jan  9 00:20:23 edge ppp: [wan]   IPADDR A.B.C.D
Jan  9 00:20:23 edge ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent
Jan  9 00:20:23 edge ppp: [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan]   COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jan  9 00:20:23 edge ppp: [wan] IPCP: SendConfigReq #2
Jan  9 00:20:23 edge ppp: [wan]   IPADDR 0.0.0.0
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: rec'd Protocol Reject #3 (Opened)
Jan  9 00:20:23 edge ppp: [wan_link0] LCP: protocol IPV6CP was rejected
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: protocol was rejected by peer
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: state change Req-Sent --> Stopped
Jan  9 00:20:23 edge ppp: [wan] IPV6CP: LayerFinish
Jan  9 00:20:23 edge ppp: [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan]   IPADDR E.F.G.H
Jan  9 00:20:23 edge ppp: [wan]     E.F.G.H is OK
Jan  9 00:20:23 edge ppp: [wan] IPCP: SendConfigReq #3
Jan  9 00:20:23 edge ppp: [wan]   IPADDR E.F.G.H
Jan  9 00:20:23 edge ppp: [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent)
Jan  9 00:20:23 edge ppp: [wan]   IPADDR E.F.G.H
Jan  9 00:20:23 edge ppp: [wan] IPCP: state change Ack-Sent --> Opened
Jan  9 00:20:23 edge ppp: [wan] IPCP: LayerUp
Jan  9 00:20:23 edge ppp: [wan]   E.F.G.H -> A.B.C.D
Jan  9 00:20:24 edge ppp: [wan] IFACE: Up event
Jan  9 00:20:24 edge ppp: [wan] IFACE: Rename interface ng0 to pppoe1

    The failure seems to be with the CHAP sending as typified by:

    
Jan  9 00:16:35 edge ppp: [wan_link0] CHAP: Using authname "********************"
Jan  9 00:16:35 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:37 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:39 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:41 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:43 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:45 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:47 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:49 edge ppp: [wan_link0] CHAP: sending RESPONSE #1 len: 52
Jan  9 00:16:51 edge ppp: [wan_link0] CHAP
    0
  • A

    PS. this was with a build from early January - replication of the problem is random and, it being midnight when this happened, I forgot to capture the syslog…. ::)

    0
  • X

    i think ur suffering this but in ur case its CHAP whereas for me its just continues reconnect loop
    http://forum.pfsense.org/index.php/topic,41061.0.html

    0
  • A

    Yes, I'd seen that topic, but thought it might get a bit of attention here as it's a 2.1 related thing.

    When it happens again, I'll get more logs….

    0
  • X

    this has been since 2.0.x till date

    0
  • A

    Yes, I should have said ALSO a 2.1 related thing.

    Devs: this happens pretty infrequently for me, but it DOES happen. Is there any debug log/settings you want us to enable to get more visibility?

    0
  • X

    actually ermal would know better as he handles this i guess, im not the developer

    0
Log in to reply
 

Products

Applications

Support

Services

News

Resources

Company

Our Mission

As host of the pfSense open source firewall project, Netgate believes in enhancing network connectivity that maintains both security and privacy. We also believe everyone should be able to afford it.

Subscribe to our Newsletter

Product information, software announcements, and special offers. See our newsletter archive for past announcements.

© Copyright 2002 - 2019 Rubicon Communications, LLC | Privacy Policy