PPPoE: Occasional disconnect; CHAP response failure; reboot needed.
-
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
-
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…. ::)
-
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 -
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….
-
this has been since 2.0.x till date
-
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?
-
actually ermal would know better as he handles this i guess, im not the developer