Timeout on LCP connections

[raulfer]

I'm trying to find out why LCP messages from debug are sending TIMEout and droping the call, here the debug messages:

Jan 21 16:29:01 CST: CHAT65: Chat script DBU finished, status = Success

Jan 21 16:29:01 CST: As65 PPP: Async Protocol Mode started for 0.0.0.0

Jan 21 16:29:03 CST: %LINK-3-UPDOWN: Interface Async65, changed state to up

Jan 21 16:29:03 CST: As65 PPP: Treating connection as a callout

Jan 21 16:29:03 CST: As65 PPP: Phase is ESTABLISHING, Active Open

Jan 21 16:29:03 CST: As65 LCP: O CONFREQ [Closed] id 34 len 25

Jan 21 16:29:03 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:03 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:03 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:03 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:03 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:05 CST: As65 LCP: TIMEout: Time 0x73A0C State REQsent

Jan 21 16:29:05 CST: As65 LCP: O CONFREQ [REQsent] id 35 len 25

Jan 21 16:29:05 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:05 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:05 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:05 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:05 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:07 CST: As65 LCP: TIMEout: Time 0x742A4 State REQsent

Jan 21 16:29:07 CST: As65 LCP: O CONFREQ [REQsent] id 36 len 25

Jan 21 16:29:07 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:07 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:07 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:07 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:07 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:09 CST: As65 LCP: TIMEout: Time 0x74A74 State REQsent

Jan 21 16:29:09 CST: As65 LCP: O CONFREQ [REQsent] id 37 len 25

Jan 21 16:29:09 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:09 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:09 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:09 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:09 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:11 CST: As65 LCP: TIMEout: Time 0x75244 State REQsent

Jan 21 16:29:11 CST: As65 LCP: O CONFREQ [REQsent] id 38 len 25

Jan 21 16:29:11 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:11 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:11 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:11 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:11 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:13 CST: As65 LCP: TIMEout: Time 0x75A14 State REQsent

Jan 21 16:29:13 CST: As65 LCP: O CONFREQ [REQsent] id 39 len 25

Jan 21 16:29:13 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:13 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:13 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:13 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:13 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:15 CST: As65 LCP: TIMEout: Time 0x761E4 State REQsent

Jan 21 16:29:15 CST: As65 LCP: O CONFREQ [REQsent] id 40 len 25

Jan 21 16:29:15 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:15 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:15 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:15 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:15 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:17 CST: As65 LCP: TIMEout: Time 0x769B4 State REQsent

Jan 21 16:29:17 CST: As65 LCP: O CONFREQ [REQsent] id 41 len 25

Jan 21 16:29:17 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:17 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:17 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:17 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:17 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:19 CST: As65 LCP: TIMEout: Time 0x771A0 State REQsent

Jan 21 16:29:19 CST: As65 LCP: O CONFREQ [REQsent] id 42 len 25

Jan 21 16:29:19 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:19 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:19 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:19 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:19 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:21 CST: As65 LCP: TIMEout: Time 0x77970 State REQsent

Jan 21 16:29:21 CST: As65 LCP: O CONFREQ [REQsent] id 43 len 25

Jan 21 16:29:21 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:21 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:21 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:21 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:21 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:23 CST: As65 LCP: TIMEout: Time 0x78144 State REQsent

Jan 21 16:29:23 CST: As65 LCP: O CONFREQ [REQsent] id 44 len 25

Jan 21 16:29:23 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:23 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:23 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:23 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:23 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:25 CST: As65 LCP: TIMEout: Time 0x78914 State REQsent

Jan 21 16:29:25 CST: TTY65: Async Int reset: Dropping DTR

Jan 21 16:29:25 CST: TTY65: Set DTR to 0

Jan 21 16:29:25 CST: As65 LCP: State is Listen

Jan 21 16:29:27 CST: %LINK-5-CHANGED: Interface Async65, changed state to reset

Jan 21 16:29:27 CST: As65 LCP: State is Closed

Jan 21 16:29:27 CST: As65 PPP: Phase is DOWN

Jan 21 16:29:30 CST: Async65: Async protocol mode stopped for 0.0.0.0

Jan 21 16:29:30 CST: Async65: asking modem_process to hangup TTY65

Jan 21 16:29:31 CST: TTY65: dropping DTR, hanging up

Jan 21 16:29:31 CST: TTY65: Set DTR to 0

Jan 21 16:29:31 CST: tty65: Modem: HANGUP->IDLE

Jan 21 16:29:32 CST: %LINK-3-UPDOWN: Interface Async65, changed state to down

Jan 21 16:29:32 CST: As65 LCP: State is Closed

Jan 21 16:29:32 CST: As65 PPP: Phase is DOWN

Jan 21 16:29:36 CST: TTY65: restoring DTR

Jan 21 16:29:36 CST: TTY65: Set DTR to 1

Jan 21 16:29:37 CST: TTY65: autoconfigure probe started

Jan 21 16:29:47 CST: Async65: re-enable timeout

[tepatel]

The router sends LCP: TIMEout, because it didn't receive the LCP response for its previous LCPREQ packet from client in timely manner (2 secs). You need to configure the router so that it gives milliseconds level time for debug using followinf commands in global config

service timestamps debug datetime msec

service timestamps log datetime msec

So you can see that the initial "O CONFREQ [Closed] id 34" from router to client didn't get replied by client in 2 secs, so router got "TIMEout: Time 0x73A0C State REQsent" and sent another "O CONFREQ [REQsent] id 35 len 25" with id 35.

[raulfer]

I tried changing those lines and didn't work.

Thanks.

[makchitale]

After the modem layer comes up, ppp exchange starts between the peers.

What we see here is that this end is sending a LCP req which is not being responded (or if responded by peer not understood maybe due packet corruption)...it will be interesting to see the same debugs on the remote end too.

1)Need to know the remote end node this end is calling into?

2)What modem are we using at both ends? I assume it's external modem on the aux port (line 65).

deb ppp nego on both end will be useful.

Thanks, Mak.

[a.manosca]

As mentioned above, the debug shows that the router is not receiving

a reply from the other device.

Jan 21 16:29:03 CST: As65 LCP: O CONFREQ [Closed] id 34 len 25

Jan 21 16:29:03 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:03 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:03 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:03 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:03 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:05 CST: As65 LCP: TIMEout: Time 0x73A0C State REQsent

Jan 21 16:29:05 CST: As65 LCP: O CONFREQ [REQsent] id 35 len 25

Jan 21 16:29:05 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:05 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:05 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:05 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:05 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:07 CST: As65 LCP: TIMEout: Time 0x742A4 State REQsent

Jan 21 16:29:07 CST: As65 LCP: O CONFREQ [REQsent] id 36 len 25

Jan 21 16:29:07 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 21 16:29:07 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 21 16:29:07 CST: As65 LCP: MagicNumber 0x0A4896BD (0x05060A4896BD)

Jan 21 16:29:07 CST: As65 LCP: PFC (0x0702)

Jan 21 16:29:07 CST: As65 LCP: ACFC (0x0802)

Jan 21 16:29:09 CST: As65 LCP: TIMEout: Time 0x74A74 State REQsent

All you can see are "O"'s. There should be "I"'s, similar to this:

Mar 13 10:57:15.415: As1 LCP: O CONFREQ [ACKrcvd] id 2 len 25

Mar 13 10:57:15.415: As1 LCP: ACCM 0x000A0000 (0x0206000A0000)

Mar 13 10:57:15.415: As1 LCP: AuthProto CHAP (0x0305C22305)

Mar 13 10:57:15.415: As1 LCP: MagicNumber 0x1084F0A2 (0x05061084F0A2)

Mar 13 10:57:15.415: As1 LCP: PFC (0x0702)

Mar 13 10:57:15.415: As1 LCP: ACFC (0x0802)

Mar 13 10:57:15.543: As1 LCP: I CONFACK [REQsent] id 2 len 25

Mar 13 10:57:15.543: As1 LCP: ACCM 0x000A0000 (0x0206000A0000)

Mar 13 10:57:15.543: As1 LCP: AuthProto CHAP (0x0305C22305)

Mar 13 10:57:15.543: As1 LCP: MagicNumber 0x1084F0A2 (0x05061084F0A2)

Mar 13 10:57:15.543: As1 LCP: PFC (0x0702)

Mar 13 10:57:15.547: As1 LCP: ACFC (0x0802)

Mar 13 10:57:16.919: As1 LCP: I CONFREQ [ACKrcvd] id 4 len 23

Mar 13 10:57:16.919: As1 LCP: ACCM 0x000A0000 (0x0206000A0000)

Mar 13 10:57:16.919: As1 LCP: MagicNumber 0x001327B0 (0x0506001327B0)

Mar 13 10:57:16.919: As1 LCP: PFC (0x0702)

Mar 13 10:57:16.919: As1 LCP: ACFC (0x0802)

Mar 13 10:57:16.919: As1 LCP: Callback 6 (0x0D0306)

Mar 13 10:57:16.919: As1 LCP: O CONFREJ [ACKrcvd] id 4 len 7

Mar 13 10:57:16.919: As1 LCP: Callback 6 (0x0D0306)

Mar 13 10:57:17.047: As1 LCP: I CONFREQ [ACKrcvd] id 5 len 20

Mar 13 10:57:17.047: As1 LCP: ACCM 0x000A0000 (0x0206000A0000)

Mar 13 10:57:17.047: As1 LCP: MagicNumber 0x001327B0 (0x0506001327B0)

Mar 13 10:57:17.047: As1 LCP: PFC (0x0702)

Mar 13 10:57:17.047: As1 LCP: ACFC (0x0802)

Mar 13 10:57:17.047: As1 LCP: O CONFACK [ACKrcvd] id 5 len 20

Mar 13 10:57:17.047: As1 LCP: ACCM 0x000A0000 (0x0206000A0000)

Mar 13 10:57:17.047: As1 LCP: MagicNumber 0x001327B0 (0x0506001327B0)

Mar 13 10:57:17.047: As1 LCP: PFC (0x0702)

Mar 13 10:57:17.047: As1 LCP: ACFC (0x0802)

Mar 13 10:57:17.047: As1 LCP: State is Open

This indicates a speed mismatch. Try setting the correct speed under "line " or you can try using "modem autoconfigure discovery" and remove the speed command.

Hope this helps.

[raulfer]

I'm using the following line aux config:

line aux 0

password 7 ?????????

script dialer DBU

login

modem InOut

modem autoconfigure discovery

transport input all

speed 115200

flowcontrol hardware

This is the standard config I'm using on 50 equipment, only 4 are not working and send the LCP timeout.

[raulfer]

At remote end (caller) we're using codex3460 modem, at local end using an AS5300 mica modem.

Here the debug ppp neg at remote end

Jan 22 09:41:06.250 CST: %LINK-3-UPDOWN: Interface Async65, changed state to up

Jan 22 09:41:06.250 CST: As65 PPP: Treating connection as a callout

Jan 22 09:41:06.250 CST: As65 PPP: Phase is ESTABLISHING, Active Open

Jan 22 09:41:06.250 CST: As65 LCP: O CONFREQ [Closed] id 78 len 25

Jan 22 09:41:06.250 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:06.250 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:06.250 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:06.250 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:06.250 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:09.194 CST: As65 LCP: TIMEout: Time 0x3B81664 State REQsent

Jan 22 09:41:09.194 CST: As65 LCP: O CONFREQ [REQsent] id 79 len 25

Jan 22 09:41:09.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:09.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:09.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:09.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:09.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:11.194 CST: As65 LCP: TIMEout: Time 0x3B821E4 State REQsent

Jan 22 09:41:11.194 CST: As65 LCP: O CONFREQ [REQsent] id 80 len 25

Jan 22 09:41:11.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:11.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:11.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:11.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:11.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:13.194 CST: As65 LCP: TIMEout: Time 0x3B829B4 State REQsent

Jan 22 09:41:13.194 CST: As65 LCP: O CONFREQ [REQsent] id 81 len 25

Jan 22 09:41:13.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:13.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:13.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:13.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:13.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:15.194 CST: As65 LCP: TIMEout: Time 0x3B83184 State REQsent

Jan 22 09:41:15.194 CST: As65 LCP: O CONFREQ [REQsent] id 82 len 25

Jan 22 09:41:15.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:15.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:15.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:15.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:15.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:17.194 CST: As65 LCP: TIMEout: Time 0x3B83954 State REQsent

Jan 22 09:41:17.194 CST: As65 LCP: O CONFREQ [REQsent] id 83 len 25

Jan 22 09:41:17.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:17.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:17.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:17.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:17.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:19.198 CST: As65 LCP: TIMEout: Time 0x3B84124 State REQsent

Jan 22 09:41:19.198 CST: As65 LCP: O CONFREQ [REQsent] id 84 len 25

Jan 22 09:41:19.198 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:19.198 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:19.198 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:19.198 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:19.198 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:21.198 CST: As65 LCP: TIMEout: Time 0x3B848F8 State REQsent

Jan 22 09:41:21.198 CST: As65 LCP: O CONFREQ [REQsent] id 85 len 25

Jan 22 09:41:21.198 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:21.198 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:21.198 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:21.198 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:21.198 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:23.198 CST: As65 LCP: TIMEout: Time 0x3B850C8 State REQsent

Jan 22 09:41:23.198 CST: As65 LCP: O CONFREQ [REQsent] id 86 len 25

Jan 22 09:41:23.198 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:23.198 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:23.198 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:23.198 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:23.198 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:25.202 CST: As65 LCP: TIMEout: Time 0x3B85898 State REQsent

Jan 22 09:41:25.202 CST: As65 LCP: O CONFREQ [REQsent] id 87 len 25

Jan 22 09:41:25.202 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:25.202 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:25.202 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:25.202 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:25.202 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:27.203 CST: As65 LCP: TIMEout: Time 0x3B8606C State REQsent

Jan 22 09:41:27.203 CST: As65 LCP: O CONFREQ [REQsent] id 88 len 25

Jan 22 09:41:27.203 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:27.203 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:27.203 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:27.203 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:27.203 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:29.203 CST: As65 LCP: TIMEout: Time 0x3B8683C State REQsent

Jan 22 09:41:29.203 CST: As65 LCP: State is Listen

Jan 22 09:41:31.203 CST: %LINK-5-CHANGED: Interface Async65, changed state to re

set

Jan 22 09:41:31.203 CST: As65 LCP: State is Closed

Jan 22 09:41:31.203 CST: As65 PPP: Phase is DOWN

Jan 22 09:41:36.203 CST: %LINK-3-UPDOWN: Interface Async65, changed state to dow

n

Jan 22 09:41:36.203 CST: As65 LCP: State is Closed

Jan 22 09:41:36.203 CST: As65 PPP: Phase is DOWN

Here the debug ppp neg at local end (AS5300)

3w5d: %LINK-5-CHANGED: Interface Async99, changed state to reset

3w5d: As99 IPCP: State is Closed

3w5d: As99 CDPCP: State is Closed

3w5d: As99 PPP: Phase is TERMINATING

3w5d: As99 LCP: State is Closed

3w5d: As99 PPP: Phase is DOWN

3w5d: As99 IPCP: Remove route to 10.3.115.190

3w5d: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async99, changed state to

down

3w5d: %LINK-3-UPDOWN: Interface Async55, changed state to up

3w5d: As55 PPP: Treating connection as a dedicated line

3w5d: As55 PPP: Phase is ESTABLISHING, Active Open

3w5d: As55 LCP: O CONFREQ [Closed] id 78 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [REQsent] id 79 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [REQsent] id 79 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 79 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: %LINK-3-UPDOWN: Interface Async99, changed state to down

3w5d: As99 LCP: State is Closed

3w5d: As55 LCP: I CONFREQ [ACKsent] id 80 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 80 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 80 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 81 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 81 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 81 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 82 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 82 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 82 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 83 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 83 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 83 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 84 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 84 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 84 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 85 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 85 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 85 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 86 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 86 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 86 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 87 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 87 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 87 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: I CONFREQ [ACKsent] id 88 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 88 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: O CONFREQ [ACKsent] id 88 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x8C18658F (0x05068C18658F)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: TIMEout: State ACKsent

3w5d: As55 LCP: State is Listen

3w5d: %LINK-5-CHANGED: Interface Async55, changed state to reset

3w5d: As55 LCP: State is Closed

3w5d: As55 PPP: Phase is DOWN

3w5d: %LINK-3-UPDOWN: Interface Async55, changed state to down

3w5d: As55 LCP: State is Closed

Thanks

[tepatel]

Pl. open a case by logging at following url to resolve the issue.

www.cisco.com/tac

[a.manosca]

From the debugs on the AS5300, it shows that the AS53

acknowledges the CONFREQ from remote end:

3w5d: As55 LCP: I CONFREQ [ACKsent] id 81 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

3w5d: As55 LCP: O CONFACK [ACKsent] id 81 len 25

3w5d: As55 LCP: ACCM 0x000A0000 (0x0206000A0000)

3w5d: As55 LCP: AuthProto CHAP (0x0305C22305)

3w5d: As55 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

3w5d: As55 LCP: PFC (0x0702)

3w5d: As55 LCP: ACFC (0x0802)

But from the remote end's debug, there's no reply:

Jan 22 09:41:06.250 CST: As65 LCP: O CONFREQ [Closed] id 78 len 25

Jan 22 09:41:06.250 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:06.250 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:06.250 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:06.250 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:06.250 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:09.194 CST: As65 LCP: TIMEout: Time 0x3B81664 State REQsent

Jan 22 09:41:09.194 CST: As65 LCP: O CONFREQ [REQsent] id 79 len 25

Jan 22 09:41:09.194 CST: As65 LCP: ACCM 0x000A0000 (0x0206000A0000)

Jan 22 09:41:09.194 CST: As65 LCP: AuthProto CHAP (0x0305C22305)

Jan 22 09:41:09.194 CST: As65 LCP: MagicNumber 0x0DF97319 (0x05060DF97319)

Jan 22 09:41:09.194 CST: As65 LCP: PFC (0x0702)

Jan 22 09:41:09.194 CST: As65 LCP: ACFC (0x0802)

Jan 22 09:41:11.194 CST: As65 LCP: TIMEout: Time 0x3B821E4 State REQsent

When using modem autoconfigure discovery. you have to remove the

speed command because it should be automatically negotiated.

(note: autoconfigure doesn't only negotiate the speed parameter)

So you should remove the line "speed 115200".

Another option is to try setting the correct speed of the modem

connected to the remote end under line aux 0.

(But don't use it simultaneously with modem autoconfigure)

Has the remote end made a successful connection before?

If not, try removing some commands from your line aux 0.

Something like:

line aux 0

modem inout

modem autoconfigure discovery

transport input all

stopbits 1

autoselect ppp

flowcontrol hardware

Goodluck!

[raulfer]

Thanks!

I can't remove speed statement, I tried removing lines but still having timeout. I tried also setting the speed removing modem autoconfigure statement, but no luck,

This connection used to be working before, in fact I have other 46 equipment with this config on them:

line aux 0

password 7 (deleted)

script dialer DBU

login

modem InOut

modem autoconfigure discovery

transport input all

speed 115200

flowcontrol hardware

Thanks!

[a.manosca]

If it has been working before, and assuming no changes were made in the

router and on the AS5300, I would try performing some hardware/line isolations.

There are a number of isolations to be done but you should not go beyond

layer 2 because the problem lies between L1-L2,

If it is possible, I hope you could try the following isolations (1-by-1):

1. Replace the cable (router-to-modem).

2. Use another line.

3. Use another modem (preferably the one used in other routers, if possible)

Is it also possible if you could post the output of "show line aux 0"?

Thanks.

[raulfer]

Thanks!

Let me tell you that we have made this and also we have changed the router itself, we are going to work again with other line and other modem but the modem it's the same for all 50 sites Motorola (Telenetics) 3640.

I'm also posting the sh line aux 0, I heve never used this command before.

rtrSUB04484#sh line aux 0

Tty Typ Tx/Rx A Modem Roty AccO AccI Uses Noise Overruns

65 AUX 115200/115200 - inout - - - 0 3 45/0

Line 65, Location: "", Type: ""

Length: 24 lines, Width: 80 columns

Baud rate (TX/RX) is 115200/115200, no parity, 2 stopbits, 8 databits

Status: No Exit Banner

Capabilities: Hardware Flowcontrol In, Hardware Flowcontrol Out

Modem Callout, Modem RI is CD

Modem state: Idle

Modem hardware state: CTS* noDSR DTR RTS

Special Chars: Escape Hold Stop Start Disconnect Activation

^^x none - - none

Timeouts: Idle EXEC Idle Session Modem Answer Session Dispatch

00:10:00 never none not set

Idle Session Disconnect Warning

never

Modem type is unknown.

Session limit is not set.

Time since activation: never

Editing is enabled.

History is enabled, history size is 10.

DNS resolution in show commands is enabled

Full user help is disabled

Allowed transports are pad v120 telnet rlogin. Preferred is telnet.

No output characters are padded

No special data dispatching characters

Thanks again!

[a.manosca]

The show line aux 0 simply shows the parameters of the

terminal or line you are using for dialin or dialout.

As you can see from the output, the speed "115200" that

you have configured on the command line was used

to set the speed of line aux 0. Also, the stopbits was

set to 2. I can't comment further about your modem settings

because you mentioned you have used it in many sites.

But If I'm going to compare this with my experience on

this kind of setup, I usually configure line aux 0 with

the exact modem speed capability and a stopbits of 1.

I tried to look for some info about the Telenetics 3460

and I think this modem supports up to 33.6kbps, please

correct me if I'm wrong.

I'm wondering why you can't change the speed command.

Would it be possible if you try, again, using the ff speed:

- 38400

- 33600

- 28800

Try using the "txspeed " and "rxspeed " commands

instead of the "speed " command.

Also, is it possible for you to compare the show line aux 0

of this router to other routers? There kinds of output would

ne useful:

1. show line aux 0 from a working router currently connected

2. show line aux 0 from another working router (not connected)

Thanks and regards.

[raulfer]

Thanks for your interest.

I already have the exact same configuration on three routers and here the differences:

The one not working:

Noise 3

Overrruns 45/0

The one disconnected but it works:

Noise 0

Overrruns 384/7453

The one connected and working:

Tty A 65

Overruns 2/0

Status: Ready, Active, No Exit Banner, Async Interface Active Modem Detected

Modem state: Ready

Line is running PPP routing for address "ip address"

0 output packets queued, 1 input packets.

Modem hardware state: CTS* DSR* DTR RTS, Modem Configured

About the speed I have configured on the working ones modem autoconfigure discovery but someone (maybe you) suggested removing that line and set the right speed or remove the speed statemet, I'm able to modify speed statement but I cannot delete it to set the default. I tried setting the speeds but I couldn't set 33600, I set 38400 and 28800 but still doesn't work.

About the telenetics 3460 it supports 33.6Kbps.

Thanks

[raulfer]

Thanks for your help, I tried removing modem autoconfigure discovery statement and again reviewing the speed at modem we fixed to 38400 and it works. I will try the same on the other 3 sites.

Thanks for your help and interest.