From: Omer Ansari (omer@xxxxxxxxxx)
Date: Tue Jul 16 2002 - 22:01:33 GMT-3
Kim,
your configs look ok, except you have dialer load-threshold on both sides
of the link; can't see how thats causing the callback to not happen. the
debugs do show that it is negotiated ok, just that RouterB has trouble
calling back after initial call termination. as if the callback timer on
RouterB is not expiring at all. (though it is 15 seconds by default, try
forcing it by manually specifying dialer enable-timeout on RouterB to
something small?
(btw i'm assuming RouterB can dial out correctly by regular interesting
traffic?)
anyhow , with 12.1(15) on 2600s heres my code if this helps:
R1:
--- username R2 password 0 ww ! interface BRI0/0 ip address 12.0.1.1 255.255.255.0 encapsulation ppp dialer idle-timeout 30 dialer map ip 12.0.1.2 name R2 broadcast 4724821 dialer-group 1 isdn switch-type basic-ni isdn spid1 919472482200 4724822 ppp callback request ppp authentication chap callin ! dialer-list 1 protocol ip permitR2: --- username R1 password 0 ww ! interface BRI0/0 ip address 12.0.1.2 255.255.255.0 encapsulation ppp dialer callback-secure dialer idle-timeout 45 dialer enable-timeout 3 dialer map ip 12.0.1.1 name R1 class high_class broadcast 4724822 dialer-group 1 isdn switch-type basic-5ess no peer default ip address ppp callback accept ppp authentication chap callin ! map-class dialer high_class dialer callback-server username dialer idle-timeout 60 dialer-list 1 protocol ip permit !
the debugs generated from the above: note the callback timer expiring on R2 after the specified 3 seconds (dialer enable-timeout 3)
----
R1#ping 12.0.1.2
Type escape sequence to abort. Sending 5, 100-byte ICMP Echos to 12.0.1.2, timeout is 2 seconds:
*Mar 1 21:36:07.290: BR0/0 DDR: Dialing cause ip (s=12.0.1.1, d=12.0.1.2) *Mar 1 21:36:07.290: BR0/0 DDR: Attempting to dial 4724821 *Mar 1 21:36:07.542: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up *Mar 1 21:36:07.586: BR0/0:1 DDR: Callback negotiated - Disconnecting now *Mar 1 21:36:07.586: BR0/0:1 DDR: disconnecting call *Mar 1 21:36:07.590: %ISDN-6-CONNECT: Interface BRI0/0:1 is now connected to 47 24821 *Mar 1 21:36:07.754: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down *Mar 1 21:36:07.762: DDR: Callback client for 4724821 created *Mar 1 21:36:07.762: BR0/0:1 DDR: disconnecting call. *Mar 1 21:36:10.718: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up.!! ! Success rate is 60 percent (3/5), round-trip min/avg/max = 32/32/32 ms R1# *Mar 1 21:36:10.874: BR0/0:1 DDR: Callback received from 4724821 *Mar 1 21:36:10.874: DDR: Freeing callback to 4724821 *Mar 1 21:36:10.886: BR0/0:1 DDR: dialer protocol up *Mar 1 21:36:11.874: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0/0:1, changed state to p *Mar 1 21:36:16.726: %ISDN-6-CONNECT: Interface BRI0/0:1 is now connected to 47 24821 R2 *Mar 1 21:36:41.354: BR0/0:1 DDR: idle timeout *Mar 1 21:36:41.354: BR0/0:1 DDR: disconnecting call *Mar 1 21:36:41.354: %ISDN-6-DISCONNECT: Interface BRI0/0:1 disconnected from 4724821 R2, call asted 30 seconds *Mar 1 21:36:41.442: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down *Mar 1 21:36:41.450: BR0/0:1 DDR: disconnecting call *Mar 1 21:36:42.442: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0/0:1, changed state to own
R2: --- R2# *Mar 1 21:35:57.554: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up *Mar 1 21:35:57.706: BR0/0:1 DDR: PPP callback Callback server starting to R1 4 724822 *Mar 1 21:35:57.706: BR0/0:1 DDR: disconnecting call *Mar 1 21:35:57.706: %ISDN-6-CONNECT: Interface BRI0/0:1 is now connected to 47 24822 R1 *Mar 1 21:35:57.810: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down *Mar 1 21:35:57.818: BR0/0:1 DDR: disconnecting call *Mar 1 21:36:00.706: DDR: Callback timer expired *Mar 1 21:36:00.706: BR0/0 DDR: beginning callback to R1 4724822 *Mar 1 21:36:00.706: BR0/0 DDR: Attempting to dial 4724822 *Mar 1 21:36:00.950: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up *Mar 1 21:36:00.954: DDR: Freeing callback to R1 4724822 *Mar 1 21:36:01.010: BR0/0:1 DDR: dialer protocol up *Mar 1 21:36:01.994: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0/0:1, changed state to p *Mar 1 21:36:06.954: %ISDN-6-CONNECT: Interface BRI0/0:1 is now connected to 47 24822 R1 *Mar 1 21:36:31.546: %ISDN-6-DISCONNECT: Interface BRI0/0:1 disconnected from 4724822 R1, call asted 30 seconds *Mar 1 21:36:31.546: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down *Mar 1 21:36:31.550: BR0/0:1 DDR: disconnecting call *Mar 1 21:36:32.546: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0/0:1, changed state to own
On Tue, 16 Jul 2002, Kim, Laurent wrote:
> Here are the configs and debug output. > > RouterA#show config > Using 1289 out of 129016 bytes > ! > version 12.1 > service timestamps debug uptime > service timestamps log uptime > no service password-encryption > ! > hostname RouterA > ! > enable password cisco > ! > username RouterB password 0 cisco > ! > ip subnet-zero > ! > isdn switch-type basic-ni > ! > interface BRI0/0 > ip address 196.1.1.1 255.255.255.0 > encapsulation ppp > dialer idle-timeout 90 > dialer map ip 196.1.1.2 name RouterB 8358662 > dialer load-threshold 1 outbound > dialer-group 1 > isdn switch-type basic-ni > isdn spid1 0835866101 8358661 > isdn spid2 0835866301 8358663 > ppp callback request > ppp authentication chap > ppp multilink > ! > ip classless > ip http server > ! > dialer-list 1 protocol ip permit > ! > line con 0 > line aux 0 > line vty 0 4 > ! > end > > > > > RouterB#show config > Using 1175 out of 129016 bytes > ! > version 12.1 > service timestamps debug uptime > service timestamps log uptime > no service password-encryption > ! > hostname RouterB > ! > enable password cisco > ! > username RouterA password 0 cisco > ! > ip subnet-zero > ! > isdn switch-type basic-ni > ! > interface BRI0/0 > ip address 196.1.1.2 255.255.255.0 > encapsulation ppp > dialer idle-timeout 90 > dialer map ip 196.1.1.1 name RouterA class callback1 8358661 > dialer load-threshold 1 outbound > dialer-group 1 > isdn switch-type basic-ni > isdn spid1 0835866201 8358662 > isdn spid2 0835866401 8358664 > ppp callback accept > ppp authentication chap > ppp multilink > ! > ip classless > ip http server > ! > map-class dialer callback1 > dialer callback-server username > dialer-list 1 protocol ip permit > ! > line con 0 > line aux 0 > line vty 0 4 > ! > end > > > RouterA#show debug > Dial on demand: > Dial on demand events debugging is on > PPP: > PPP authentication debugging is on > PPP protocol negotiation debugging is on > ISDN: > ISDN Q931 packets debugging is on > ISDN Q931 packets debug DSLs. (On/Off/No DSL:1/0/-) > DSL 0 --> 31 > 1 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - > > Callback: > Callback activity debugging is on > RouterA#ping 196.1.1.2 > > Type escape sequence to abort. > Sending 5, 100-byte ICMP Echos to 196.1.1.2, timeout is 2 seconds: > > 00:14:02: BR0/0 DDR: Dialing cause ip (s=196.1.1.1, d=196.1.1.2) > 00:14:02: BR0/0 DDR: Attempting to dial 8358662 > 00:14:02: ISDN BR0/0: TX -> SETUP pd = 8 callref = 0x04 > 00:14:02: Bearer Capability i = 0x8890 > 00:14:02: Channel ID i = 0x83 > 00:14:02: Keypad Facility i = '8358662' > 00:14:02: ISDN BR0/0: RX <- CALL_PROC pd = 8 callref = 0x84 > 00:14:02: Channel ID i = 0x89 > 00:14:02: Locking Shift to Codeset 5 > 00:14:02: Codeset 5 IE 0x2A i = 0x808307, '8358662', 0x8E0B20, > 'Teltone', 0x20, '2', 0x20 > 00:14:02: ISDN BR0/0: RX <- CONNECT pd = 8 callref = 0x84 > 00:14:02: ISDN BR0/0: TX -> CONNECT_ACK pd = 8 callref = 0x04 > 00:14:02: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up > 00:14:02: BR0/0:1 PPP: Treating connection as a callout > 00:14:02: BR0/0:1 PPP: Phase is ESTABLISHING, Active Open > 00:14:02: BR0/0:1 LCP: O CONFREQ [Closed] id 4 len 32 > 00:14:02: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:14:02: BR0/0:1 LCP: MagicNum.ber 0x030A52A5 (0x0506030A52A5) > 00:14:02: BR0/0:1 LCP: Callback 0 (0x0D0300) > 00:14:02: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:14:02: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657241) > 00:14:02: BR0/0:1 LCP: I CONFREQ [REQsent] id 3 len 29 > 00:14:02: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:14:02: BR0/0:1 LCP: MagicNumber 0x0464B87A (0x05060464B87A) > 00:14:02: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:14:02: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657242) > 00:14:02: BR0/0:1 LCP: O CONFACK [REQsent] id 3 len 29 > 00:14:02: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:14:02: BR0/0:1 LCP: MagicNumber 0x0464B87A (0x05060464B87A) > 00:14:02: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:14:02: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657242) > 00:14:02: BR0/0:1 LCP: I CONFACK [ACKsent] id 4 len 32 > 00:14:02: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:14:02: BR0/0:1 LCP: MagicNumber 0x030A52A5 (0x0506030A52A5) > 00:14:02: BR0/0:1 LCP: Callback 0 (0x0D0300) > 00:14:02: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:14:02: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657241) > 00:14:02: BR0/0:1 LCP: State is Open > 00:14:02: BR0/0:1 PPP: Phase is AUTHENTICATING, by both > 00:14:02: BR0/0:1 CHAP: O CHALLENGE id 3 len 28 from "RouterA" > 00:14:02: BR0/0:1 CHAP: I CHALLENGE id 3 len 28 from "RouterB" > 00:14:02: BR0/0:1 CHAP: O RESPONSE id 3 len 28 from "RouterA" > 00:14:02: BR0/0:1 CHAP: I SUCCESS id 3 len 4 > 00:14:02: BR0/0:1 CHAP: I RESPONSE id 3 len 28 from "RouterB" > 00:14:02: BR0/0:1 CHAP: O SUCCESS id 3 len 4 > 00:14:02: BR0/0:1 DDR: Callback negotiated - Disconnecting now > 00:14:02: BR0/0:1 DDR: disconnecting call > 00:14:02: %ISDN-6-CONNECT: Int.erface BRI0/0:1 is now connected to 8358662 > RouterB > 00:14:02: ISDN BR0/0: TX -> DISCONNECT pd = 8 callref = 0x04 > 00:14:02: Cause i = 0x8090 - Normal call clearing > 00:14:02: ISDN BR0/0: RX <- RELEASE pd = 8 callref = 0x84 > 00:14:02: ISDN BR0/0: TX -> RELEASE_COMP pd = 8 callref = 0x04 > 00:14:02: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down > 00:14:02: DDR: Callback client for RouterB 8358662 created > 00:14:02: BR0/0:1 PPP: Phase is TERMINATING > 00:14:02: BR0/0:1 LCP: State is Closed > 00:14:02: BR0/0:1 PPP: Phase is DOWN > 00:14:02: BR0/0:1 DDR: disconnecting call... > Success rate is 0 percent (0/5) > RouterA# > 00:14:47: DDR: No callback received from RouterB 8358662 > 00:14:47: DDR: Freeing callback to RouterB 8358662 > > > > > RouterB#show debug > Dial on demand: > Dial on demand events debugging is on > PPP: > PPP authentication debugging is on > PPP protocol negotiation debugging is on > ISDN: > ISDN Q931 packets debugging is on > ISDN Q931 packets debug DSLs. (On/Off/No DSL:1/0/-) > DSL 0 --> 31 > 1 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - > > Callback: > Callback activity debugging is on > RouterB# > 00:25:27: ISDN BR0/0: RX <- SETUP pd = 8 callref = 0x03 > 00:25:27: Bearer Capability i = 0x8890 > 00:25:27: Channel ID i = 0x89 > 00:25:27: Signal i = 0x40 - Alerting on - pattern 0 > 00:25:27: Calling Party Number i = 'A', 0x81, '8358661', Plan:ISDN, > Type:Subscriber(local) > 00:25:27: Called Party Number i = 0xC1, '8358662', Plan:ISDN, > Type:Subscriber(local) > 00:25:27: ISDN BR0/0: Event: Received a DATA call from 8358661 on B1 at 64 > Kb/s > 00:25:27: ISDN BR0/0: TX -> CALL_PROC pd = 8 callref = 0x83 > 00:25:27: Channel ID i = 0x89 > 00:25:27: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to up > 00:25:27: BR0/0:1 PPP: Treating connection as a callin > 00:25:27: BR0/0:1 PPP: Phase is ESTABLISHING, Passive Open > 00:25:27: BR0/0:1 LCP: State is Listen > 00:25:27: ISDN BR0/0: TX -> CONNECT pd = 8 callref = 0x83 > 00:25:27: Channel ID i = 0x89 > 00:25:27: ISDN BR0/0: RX <- CONNECT_ACK pd = 8 callref = 0x03 > 00:25:27: BR0/0:1 LCP: I CONFREQ [Listen] id 4 len 32 > 00:25:27: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:25:27: BR0/0:1 LCP: MagicNumber 0x030A52A5 (0x0506030A52A5) > 00:25:27: BR0/0:1 LCP: Callback 0 (0x0D0300) > 00:25:27: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:25:27: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657241) > 00:25:27: BR0/0:1 LCP: O CONFREQ [Listen] id 3 len 29 > 00:25:27: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:25:27: BR0/0:1 LCP: MagicNumber 0x0464B87A (0x05060464B87A) > 00:25:27: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:25:27: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657242) > 00:25:27: BR0/0:1 LCP: O CONFACK [Listen] id 4 len 32 > 00:25:27: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:25:27: BR0/0:1 LCP: MagicNumber 0x030A52A5 (0x0506030A52A5) > 00:25:27: BR0/0:1 LCP: Callback 0 (0x0D0300) > 00:25:27: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:25:27: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657241) > 00:25:27: BR0/0:1 LCP: I CONFACK [ACKsent] id 3 len 29 > 00:25:27: BR0/0:1 LCP: AuthProto CHAP (0x0305C22305) > 00:25:27: BR0/0:1 LCP: MagicNumber 0x0464B87A (0x05060464B87A) > 00:25:27: BR0/0:1 LCP: MRRU 1524 (0x110405F4) > 00:25:27: BR0/0:1 LCP: EndpointDisc 1 Local (0x130A01526F7574657242) > 00:25:27: BR0/0:1 LCP: State is Open > 00:25:27: BR0/0:1 PPP: Phase is AUTHENTICATING, by both > 00:25:27: BR0/0:1 CHAP: O CHALLENGE id 3 len 28 from "RouterB" > 00:25:27: BR0/0:1 CHAP: I CHALLENGE id 3 len 28 from "RouterA" > 00:25:27: BR0/0:1 CHAP: Waiting for peer to authenticate first > 00:25:27: BR0/0:1 CHAP: I RESPONSE id 3 len 28 from "RouterA" > 00:25:27: BR0/0:1 CHAP: O SUCCESS id 3 len 4 > 00:25:27: BR0/0:1 CHAP: Processing saved Challenge, id 3 > 00:25:27: BR0/0:1 CHAP: O RESPONSE id 3 len 28 from "RouterB" > 00:25:28: ISDN BR0/0: RX <- DISCONNECT pd = 8 callref = 0x03 > 00:25:28: Cause i = 0x8290 - Normal call clearing > 00:25:28: Signal i = 0x3F - Tones off > 00:25:28: ISDN BR0/0: TX -> RELEASE pd = 8 callref = 0x83 > 00:25:28: %ISDN-6-CONNECT: Interface BRI0/0:1 is now connected to 8358661 > RouterA > 00:25:28: %ISDN-6-DISCONNECT: Interface BRI0/0:1 disconnected from 8358661 > RouterA, call lasted 1 seconds > 00:25:28: %LINK-3-UPDOWN: Interface BRI0/0:1, changed state to down > 00:25:28: BR0/0:1 PPP: Phase is TERMINATING > 00:25:28: BR0/0:1 LCP: State is Closed > 00:25:28: BR0/0:1 PPP: Phase is DOWN > 00:25:28: BR0/0:1 DDR: disconnecting call > 00:25:28: ISDN BR0/0: RX <- RELEASE_COMP pd = 8 callref = 0x03 > RouterB# > > > > I tried this config with 12.1(13), 12.1(14), 12.1(15), 12.1(16) and > 12.2(10a). If calling end is 11.2 the same configuration works fine with > any 12.1 or 12.2 on receiving end. I haven't tried 12.0 code but I'm going > to try in few minutes and let you know. > > Thank you, > > Laurent > > -----Original Message----- > > From: Omar Masood [mailto:omarmasood360@hotmail.com] > > Sent: Friday, July 16, 1999 12:19 PM > > To: ccielab@groupstudy.com; Kim, Laurent > > Subject: Re: PPP Callback on 12.1(15) > > > > > > can you paste the config > > > > kusti > > **Omar Masood 360** > > > > e/m: omarmasood360@hotmail.com > > or: omarmasood@aol.com > > ----- Original Message ----- > > From: "Kim, Laurent" <lkim@xo.com> > > To: <ccielab@groupstudy.com> > > Sent: Monday, July 15, 2002 11:36 PM > > Subject: PPP Callback on 12.1(15) > > > > > > > Hi all, > > > > > > I'm having a weird problem with a very simple ppp callback setup. > > > When > > I'm > > > using 12.1(15) image on both ends, ppp call back fails. If I use > > > 11.2(26) on calling side, the same configuration works flawlessly. > > > > > > thanks, > > > > > > Laurent
This archive was generated by hypermail 2.1.4 : Sat Sep 07 2002 - 19:36:33 GMT-3