How to verify the stability of an ADSL NIM?

[Anonymous]

I'm working with an ISP which is providing ADSL services. My ADSL connection is bouncing up and down and I'm wondering if there is any indication that can be derived from any debug output that would point the finger at my 6 year old ADSL NIM. I've looked at debug ppp verbose, which doesn't display anything too interesting as to why the connection is dropped, so is there anything else I can output to discover the reason as to why my ADSL is dropping?

Appreciate your help.

[Anonymous]

Here is some output of "debug ppp verbose":

2012.12.04 11:09:06 INTERFACE_STATUS.adsl 1/1 changed state to up

2012.12.04 11:09:06 INTERFACE_STATUS.atm 1.1 changed state to up

2012.12.04 11:09:07 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=26 Len=10 MAGIC(dd092d5c)

2012.12.04 11:09:07 INTERFACE_STATUS.atm 1 changed state to up

2012.12.04 11:09:11 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=27 Len=10 MAGIC(dd092d5c)

2012.12.04 11:09:13 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Req  ID=2 Len=14 AP(PAP)MAGIC(0d6e7762)

2012.12.04 11:09:13 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Nak  ID=2 Len=9 AP(CHAP)

2012.12.04 11:09:13 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Req  ID=3 Len=15 AP(CHAP)MAGIC(0d6e7762)

2012.12.04 11:09:13 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Ack  ID=3 Len=15 AP(CHAP)MAGIC(0d6e7762)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=28 Len=10 MAGIC(dd092d5c)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Ack  ID=28 Len=10 MAGIC(dd092d5c)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPFSM: layer up, Protocol=c021

2012.12.04 11:09:15 PPP.NEGOTIATION atm 1.1: LCP up

2012.12.04 11:09:15 PPP.AUTHENTICATION PPPrx[atm 1.1] CHAP: Challenge  ID=1 Len=49 ValLen=16 Name(slkc-dsl-gw19.slkc.qwest.net)

2012.12.04 11:09:15 PPP.AUTHENTICATION PPPtx[atm 1.1] CHAP: Response  ID=1 Len=25 ValLen=16 Name(****)

2012.12.04 11:09:15 PPP.AUTHENTICATION PPPrx[atm 1.1] CHAP: Success  ID=1 Len=4 Message()

2012.12.04 11:09:15 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Req  ID=1 Len=22 IP(0.0.0.0) PriDNS(0.0.0.0) SecDNS(0.0.0.0)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Req  ID=1 Len=10 IP(67.41.239.211)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Ack  ID=1 Len=10 IP(67.41.239.211)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Nak  ID=1 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Req  ID=2 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:09:15 INTERFACE_STATUS.ppp 1 changed state to up

2012.12.04 11:09:15 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Ack  ID=2 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:09:15 PPP.NEGOTIATION PPPFSM: layer up, Protocol=8021

2012.12.04 11:09:15 PPP.NEGOTIATION ppp 1: IPCP up

2012.12.04 11:09:25 PPP PPPtx[atm 1.1] LCP: Echo-Req MAGIC(dd092d5c)

...

2012.12.04 11:15:35 PPP PPPtx[atm 1.1] LCP: Echo-Req MAGIC(dd092d5c)

2012.12.04 11:15:35 INTERFACE_STATUS.adsl 1/1 changed state to down

2012.12.04 11:15:35 INTERFACE_STATUS.atm 1.1 changed state to down

2012.12.04 11:15:36 PPP.NEGOTIATION ppp 1: IPCP down

2012.12.04 11:15:36 PPP.NEGOTIATION atm 1.1: LCP down

2012.12.04 11:15:36 INTERFACE_STATUS.atm 1 changed state to down

2012.12.04 11:15:36 INTERFACE_STATUS.ppp 1 changed state to down

2012.12.04 11:16:00 INTERFACE_STATUS.atm 1.1 changed state to up

2012.12.04 11:16:01 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=67 Len=10 MAGIC(6a6c0752)

2012.12.04 11:16:01 INTERFACE_STATUS.adsl 1/1 changed state to up

2012.12.04 11:16:01 INTERFACE_STATUS.atm 1 changed state to up

2012.12.04 11:16:05 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=68 Len=10 MAGIC(6a6c0752)

2012.12.04 11:16:05 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Req  ID=1 Len=14 AP(PAP)MAGIC(0d74c90c)

2012.12.04 11:16:05 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Nak  ID=1 Len=9 AP(CHAP)

2012.12.04 11:16:05 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Req  ID=2 Len=15 AP(CHAP)MAGIC(0d74c90c)

2012.12.04 11:16:05 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Ack  ID=2 Len=15 AP(CHAP)MAGIC(0d74c90c)

2012.12.04 11:16:07 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Req  ID=3 Len=15 AP(CHAP)MAGIC(0d74c90c)

2012.12.04 11:16:07 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Ack  ID=3 Len=15 AP(CHAP)MAGIC(0d74c90c)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPtx[atm 1.1] LCP: Conf-Req  ID=69 Len=10 MAGIC(6a6c0752)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPrx[atm 1.1] LCP: Conf-Ack  ID=69 Len=10 MAGIC(6a6c0752)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPFSM: layer up, Protocol=c021

2012.12.04 11:16:09 PPP.NEGOTIATION atm 1.1: LCP up

2012.12.04 11:16:09 PPP.AUTHENTICATION PPPrx[atm 1.1] CHAP: Challenge  ID=1 Len=49 ValLen=16 Name(slkc-dsl-gw19.slkc.qwest.net)

2012.12.04 11:16:09 PPP.AUTHENTICATION PPPtx[atm 1.1] CHAP: Response  ID=1 Len=25 ValLen=16 Name(****)

2012.12.04 11:16:09 PPP.AUTHENTICATION PPPrx[atm 1.1] CHAP: Success  ID=1 Len=4 Message()

2012.12.04 11:16:09 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Req  ID=1 Len=22 IP(0.0.0.0) PriDNS(0.0.0.0) SecDNS(0.0.0.0)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Nak  ID=1 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Req  ID=2 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:16:09 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Ack  ID=2 Len=22 IP(70.58.39.***) PriDNS(205.171.3.65) SecDNS(205.171.2.65)

2012.12.04 11:16:09 INTERFACE_STATUS.ppp 1 changed state to up

2012.12.04 11:16:11 PPP.NEGOTIATION PPPrx[atm 1.1] IPCP: Conf-Req  ID=2 Len=10 IP(67.41.239.211)

2012.12.04 11:16:11 PPP.NEGOTIATION PPPtx[atm 1.1] IPCP: Conf-Ack  ID=2 Len=10 IP(67.41.239.211)

2012.12.04 11:16:11 PPP.NEGOTIATION PPPFSM: layer up, Protocol=8021

2012.12.04 11:16:11 PPP.NEGOTIATION ppp 1: IPCP up

2012.12.04 11:16:16 INTERFACE_STATUS.adsl 1/1 changed state to down

2012.12.04 11:16:16 INTERFACE_STATUS.atm 1.1 changed state to down

2012.12.04 11:16:17 PPP.NEGOTIATION ppp 1: IPCP down

2012.12.04 11:16:17 PPP.NEGOTIATION atm 1.1: LCP down

2012.12.04 11:16:17 INTERFACE_STATUS.atm 1 changed state to down

2012.12.04 11:16:17 INTERFACE_STATUS.ppp 1 changed state to down

[Anonymous]

I'm more familiar with the 3100 series, but could you do a "sh int adsl 1/1" ? That has more info on your actual connection. PPP travels over the ADSL circuit, and you want to resolve at the lowest level first. Or at least I do. For 8 hours a day.

Just to verify, I trimmed the log and yeah... it's not a higher level issue. Definitely something from the ADSL interface to the DSLAM inclusive.

2012.12.04 11:09:06 INTERFACE_STATUS.adsl 1/1 changed state to up

[...]

2012.12.04 11:15:35 INTERFACE_STATUS.adsl 1/1 changed state to down

[...]

2012.12.04 11:16:01 INTERFACE_STATUS.adsl 1/1 changed state to up

[...]

2012.12.04 11:16:16 INTERFACE_STATUS.adsl 1/1 changed state to down

[Anonymous · Accepted solution]

I appreciate the feedback. Alas I was unable to determine by debug where the tear down of the line was happening. However, accessing the GUI revealed a huge amount of Corrected Blocks and Uncorrected Blocks! So we ordered a new ADSL NIM, replaced it and that has resolved the issue. Just a bad card after 6 years.

Thanks again.

[Anonymous]

-

I went ahead and flagged the "Correct Answer" on this post to make it more visible and help other members of the community find solutions more easily. If you don't feel like the answer I marked was correct, feel free to come back to this post to unmark it and select another in its place with the applicable buttons.  If you have any additional information on this that others may benefit from, please come back to this post to provide an update.  If you still need assistance, we would be more than happy to continue working with you on this - just let us know in a reply.

Thanks,

Noor