Multilink PPP Across Two Serial Physical-layer Async InterfacesPrintable Pdf
Document ID: 10380
Introduction Prerequisites
Requirements
Components Used
Related Products Conventions
Configure
Network Diagram
Configurations. Verify Troubleshoot
Troubleshooting Commands Related Information
Introduction
In some environments, it may be necessary to bundle multiple asynchronous links to act as single link with
aggregated bandwidth. This document describes how to configure a Cisco 2500 Access Server to bundle two
asychronous interfaces using a virtual template.
This configuration can be used for routers connected by asynchronous lines with external modems or using
network modules (built-in modems).You can add additional features to this configuration depending on your
needs.
Prerequisites
Requirements
There are no specific prerequisites for this document.
Components Used
The information in this document is based on the software and hardware versions below.
Cisco 2511 and Cisco 2503 routers in a lab environment with cleared configurations.
Cisco IOS® Software Realease 12.2(10b) is running on both routers.
Four external modems.
The information presented in this document was created from devices in a specific lab environment. All of the
devices used in this document started with a cleared (default) configuration. If you are working in a live
network, ensure that you understand the potential impact of any command before using it.
Related Products
This configuration can be used with any two routers that each have two WAN serial interfaces and are capable
of configuring the async interface. WIC-1T, WIC-2A/S, 8 or 16 asynchronous port serial interfaces can be
used.
Conventions
For more information on document conventions, see the Cisco Technical Tips Conventions.
Configure
In this section, you are presented with the information to configure the features described in this document.
Note:To find additional information on the commands used in this document, use the Command Lookup
Tool ( registered customers only) .
Network Diagram
This document uses the network setup shown in the diagram below.
Configurations
This document uses the configurations shown below.
Note: This configuration was tested using Cisco IOS Software Release 12.2(10b) on Cisco 2500 series
routers. The same configuration applies to a similar router topology running Cisco IOS software releases
starting from Release 11.0(3).
To implement this configuration, you have to configure the following:
Create a multilink virtual-template number on Router 1.
Configure ppp multilink under the interfaces on both routers.
Configure authentication under the interfaces on both routers.
In the configuration used in this document, Router 1 has been configured to only receive calls, while Router 2
initiates the call and connects to Router 1. Both routers are configured for multilink PPP. When the
connection comes up, a master bundle is created and both async links are bundled together under a
virtual-access interface.
Interfaces 9 and 10 on Router 1 only receive async calls. It is normal not to see interface 9 and 10 when they
are part of group-async 1. Be sure to create a multilink virtual template; otherwise, it is possible to connect on
the first channel, but not pass traffic (IP Control Protocol [IPCP] closed). Without a virtual-template and
multilink PPP, this configuration would work for one async connection, but not for both.
Interfaces 2 and 3 on Router 2 are configured with the physical-layer async command and will accept
multilink PPP commands. These interfaces will automatically be removed when they become part of dialer
rotary-group. As soon as you enter the dialer rotary-group 3command, the serial ppp multilink command
is deleted from the configuration. Use theppp multilink command under interface dialer 3 instead.
Verify
This section provides information you can use to confirm your configuration is working properly.
Certain show commands are supported by the Output Interpreter Tool ( registered customers only) , which allows
you to view an analysis of show command output.
Router1#show ip route
Codes: C - connected, S - static, I - IGRP, R - RIP, M - mobile, B - BGP
D - EIGRP, EX - EIGRP external, O - OSPF, IA - OSPF inter area
N1 - OSPF NSSA external type 1, N2 - OSPF NSSA external type 2
E1 - OSPF external type 1, E2 - OSPF external type 2, E - EGP
i - IS-IS, L1 - IS-IS level-1, L2 - IS-IS level-2, ia - IS-IS inter area
* - candidate default, U - per-user static route, o - ODR
P - periodic downloaded static route
Gateway of last resort is not set
172.16.0.0/24 is subnetted, 1 subnets
O E2 172.16.1.0 [110/20] via 192.168.0.1, 00:32:54, Virtual-Access1
10.0.0.0/24 is subnetted, 1 subnets
C 10.0.0.0 is directly connected, Ethernet0
192.168.0.0/24 is variably subnetted, 2 subnets, 2 masks
C 192.168.0.0/24 is directly connected, Loopback0
C 192.168.0.1/32 is directly connected, Virtual-Access1
Router1#show ppp multilink
Virtual-Access1, bundle name is Router2
! --- Virtualized MP bundle. Bundle name is derived from the username used
!--- during authentication
Bundle up for 00:34:48
0 lost fragments, 0 reordered, 0 unassigned
0 discarded, 0 lost received, 1/255 load
0xC8 received sequence, 0xC8 sent sequence
Member links: 2 (max not set, min not set)
Async9, since 00:34:52, last rcvd seq 0000C6
Async10, since 00:32:11, last rcvd seq 0000C7
Router2#show ip route
Codes: C - connected, S - static, I - IGRP, R - RIP, M - mobile, B - BGP
D - EIGRP, EX - EIGRP external, O - OSPF, IA - OSPF inter area
N1 - OSPF NSSA external type 1, N2 - OSPF NSSA external type 2
E1 - OSPF external type 1, E2 - OSPF external type 2, E - EGP
i - IS-IS, L1 - IS-IS level-1, L2 - IS-IS level-2, ia - IS-IS inter area
* - candidate default, U - per-user static route, o - ODR
P - periodic downloaded static route
Gateway of last resort is not set
172.16.0.0/24 is subnetted, 1 subnets
C 172.16.1.0 is directly connected, Ethernet0
10.0.0.0/24 is subnetted, 1 subnets
O E2 10.0.0.0 [110/20] via 192.168.0.2, 00:45:10, Dialer3
192.168.0.0/24 is variably subnetted, 2 subnets, 2 masks
C 192.168.0.0/24 is directly connected, Loopback0
C 192.168.0.2/32 is directly connected, Dialer3
Router2#show ppp multilink
Virtual-Access1, bundle name is Router1
!--- Virtualized MP bundle. Bundle name is derived from the username used
!--- during authentication.
Bundle up for 00:35:10
Dialer interface is Dialer3
!--- This Virtual Access Interface used Interface Dialer3.
0 lost fragments, 0 reordered, 0 unassigned
0 discarded, 0 lost received, 1/255 load
0xC9 received sequence, 0xCA sent sequence
Member links: 2 (max not set, min not set)
Serial3, since 00:35:10, last rcvd seq 0000C8
Serial2, since 00:32:29, last rcvd seq 0000C7
Router1#show caller
Active Idle
Line User Service Time Time
con 0 - TTY 00:12:03 00:00:00
tty 2 - TTY 1d08h 00:00:00
tty 4 - TTY 1d08h 00:00:00
tty 9 Router2 Async 00:43:17 00:00:05
tty 10 Router2 Async 00:40:36 00:00:15
!--- First connection
As9 Router2 PPP 00:43:13 -
!--- Second connection
As10 Router2 PPP 00:40:32 -
!--- MP bundle
!--- Router2 has two async lines, two TTY, and one virtual interface bundle.
Vi1 Router2 PPP Bundle 00:43:10 00:00:05
Router2#show caller
Active Idle
Line User Service Time Time
con 0 - TTY 00:11:36 00:00:00
tty 2 Router1 Async - 00:00:07
tty 3 Router1 Async - 00:00:18
! --- Second connection
Se2 Router1 PPP 00:39:58 -
! --- First connection
Se3 Router1 PPP 00:42:39 -
! --- MP bundle
! --- Router1 has two async lines, two TTY, and one virtual interface bundle.
Vi1 Router1 PPP Bundle 00:42:39 00:00:01
Router2#show caller user Router1
User: Router1, line tty 2, service Async
Idle time 00:00:16
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 2, running PPP on Se2
Line: Baud rate (TX/RX) is 115200/115200, no parity, 2 stopbits, 8 databits
Status: Ready, Active, Async Interface Active, Modem Detected
Capabilities: Modem Callout, Modem RI is CD,
Line is permanent async interface, Hangup on Last Close
Modem Autoconfigure
Modem State: Ready, Modem Configured
User: Router1, line tty 3, service Async
Idle time 00:00:08
Timeouts: Absolute Idle Idle
Session Exec
Limits: - - 00:10:00
Disconnect in: - - -
TTY: Line 3, running PPP on Se3
Line: Baud rate (TX/RX) is 115200/115200, no parity, 2 stopbits, 8 databits
Status: Ready, Active, Async Interface Active, Modem Detected
Capabilities: Modem Callout, Modem RI is CD,
Line is permanent async interface, Hangup on Last Close
Modem Autoconfigure
Modem State: Ready, Modem Configured
User: Router1, line Se2, service PPP
Active time 23:14:47, Idle time 00:00:00
PPP: LCP Open, multilink Open, CHAP (local <--> local)
Dialer: Connected to 30116, outbound
Type is IN-BAND ASYNC, group Di3
Cause: Multilink bundle overloaded
IP: Local 192.168.0.1
Bundle: Member of Router1, last input 00:00:01
Counts: 10194 packets input, 769456 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
10247 packets output, 773761 bytes, 0 underruns
0 output errors, 0 collisions, 31 interface resets
User: Router1, line Se3, service PPP
Active time 23:17:30, Idle time 00:00:01
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, multilink Open, CHAP (local <--> local)
Dialer: Connected to 30116, outbound
Type is IN-BAND ASYNC, group Di3
Cause: ip (s=192.168.0.1, d=224.0.0.5)
IP: Local 192.168.0.1
Bundle: Member of Router1, last input 00:00:00
Counts: 10432 packets input, 783562 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
10718 packets output, 799155 bytes, 0 underruns
0 output errors, 0 collisions, 41 interface resets
User: Router1, line Vi1, service PPP Bundle
Active time 23:17:30, Idle time 00:00:05
PPP: LCP Open, multilink Open, IPCP
Dialer: Connected to 30116, outbound
Idle timer 60 secs, idle 6 secs
Type is IN-BAND SYNC, group Di3
IP: Local 192.168.0.1, remote 192.168.0.2
!--- IP address assigned to the bundle
!--- and loopback address of the remote router.
Bundle: First link of Router1, 2 links, last input 00:00:07
Counts: 8622 packets input, 623202 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
8776 packets output, 618523 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
Router2#show dialer
Di3 - dialer type = IN-BAND SYNC NO-PARITY
Load threshold for dialing additional calls is 1
!--- Load threshold
Idle timer (60 secs), Fast idle timer (20 secs)
Wait for carrier (30 secs), Re-enable (15 secs)
Number of active calls = 2
Dial String Successes Failures Last DNIS Last status
30114 3 69 00:41:45 successful
30116 4294967293 75 00:44:00 failed
Se2 - dialer type = IN-BAND ASYNC NO-PARITY
Rotary group 3, priority 0
!--- Member of interface dialer 3
Idle timer (60 secs), Fast idle timer (20 secs)
Wait for carrier (30 secs), Re-enable (15 secs)
Dialer state is multilink member
Dial reason: Multilink bundle overloaded
!--- Interface was not the first link in the MP bundle
Connected to 30116 (Router1)
!--- Phone number that was dialed
Se3 - dialer type = IN-BAND ASYNC NO-PARITY
Rotary group 3, priority 0
!--- Member of interface dialer 3
Idle timer (60 secs), Fast idle timer (20 secs)
Wait for carrier (30 secs), Re-enable (15 secs)
Dialer state is multilink member
Dial reason: ip (s=192.168.0.1, d=224.0.0.5)
!--- Interface was the first link in the bundle, triggered by OSPF ALL
!--- Routers advt packet.
Connected to 30116 (Router1)
! --- Phone number that was dialed
Troubleshoot
This section provides information you can use to troubleshoot your configuration.
The following outputs were obtained from the Cisco 2511 and Cisco 2503 routers. They show the Cisco 2503
dialing to PSTN links of the Cisco 2511 router and establishing a MP connection.
Router1#debug ppp negotiation
PPP protocol negotiation debugging is on
Router1#debug vtemplate
Virtual Template debugging is on
Router1#show debug
PPP:
PPP protocol negotiation debugging is on
VTEMPLATE:
Virtual Template debugging is on
Oct 1 20:15:20.463: As9 LCP: I CONFREQ [Closed] id 81 len 39
Oct 1 20:15:20.463: As9 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:15:20.467: As9 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:15:20.471: As9 LCP: MagicNumber 0x57D7985D (0x050657D7985D)
Oct 1 20:15:20.471: As9 LCP: PFC (0x0702)
Oct 1 20:15:20.475: As9 LCP: ACFC (0x0802)
Oct 1 20:15:20.479: As9 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:15:20.479: As9 LCP: EndpointDisc 1 Router2 (0x130A01526F7574657232)
Oct 1 20:15:20.483: As9 LCP: Lower layer not up, Fast Starting
Oct 1 20:15:20.487: As9 PPP: Treating connection as a dedicated line
Oct 1 20:15:20.487: As9 PPP: Phase is ESTABLISHING, Active Open [0 sess, 0 load]
Oct 1 20:15:20.495: As9 LCP: O CONFREQ [Closed] id 52 len 39
Oct 1 20:15:20.499: As9 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:15:20.499: As9 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:15:20.503: As9 LCP: MagicNumber 0x078F2456 (0x0506078F2456)
Oct 1 20:15:20.507: As9 LCP: PFC (0x0702)
Oct 1 20:15:20.507: As9 LCP: ACFC (0x0802)
Oct 1 20:15:20.511: As9 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:15:20.515: As9 LCP: EndpointDisc 1 Router1 (0x130A01526F7574657231)
Oct 1 20:15:20.519: As9 LCP: O CONFACK [REQsent] id 81 len 39
Oct 1 20:15:20.523: As9 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:15:20.527: As9 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:15:20.527: As9 LCP: MagicNumber 0x57D7985D (0x050657D7985D)
Oct 1 20:15:20.531: As9 LCP: PFC (0x0702)
Oct 1 20:15:20.531: As9 LCP: ACFC (0x0802)
Oct 1 20:15:20.535: As9 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:15:20.539: As9 LCP: EndpointDisc 1 Router2 (0x130A01526F7574657232)
Oct 1 20:15:20.547: %LINK-3-UPDOWN: Interface Async9, changed state to up
Oct 1 20:15:20.695: As9 LCP: I CONFACK [ACKsent] id 52 len 39
Oct 1 20:15:20.699: As9 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:15:20.703: As9 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:15:20.707: As9 LCP: MagicNumber 0x078F2456 (0x0506078F2456)
Oct 1 20:15:20.707: As9 LCP: PFC (0x0702)
Oct 1 20:15:20.711: As9 LCP: ACFC (0x0802)
Oct 1 20:15:20.711: As9 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:15:20.715: As9 LCP: EndpointDisc 1 Router1 (0x130A01526F7574657231)
Oct 1 20:15:20.719: As9 LCP: State is Open
Oct 1 20:15:20.723: As9 PPP: Phase is AUTHENTICATING, by both [0 sess, 0 load]
Oct 1 20:15:20.727: As9 CHAP: O CHALLENGE id 45 len 28 from "Router1"
Oct 1 20:15:20.739: As9 CHAP: I CHALLENGE id 40 len 28 from "Router2"
Oct 1 20:15:20.743: As9 CHAP: O RESPONSE id 40 len 28 from "Router1"
Oct 1 20:15:20.899: As9 CHAP: I RESPONSE id 45 len 28 from "Router2"
Oct 1 20:15:20.903: As9 CHAP: I SUCCESS id 40 len 4
Oct 1 20:15:20.919: As9 CHAP: O SUCCESS id 45 len 4
!--- Call is virtualized after authentication
Oct 1 20:15:20.923: As9 PPP: Phase is VIRTUALIZED [0 sess, 1 load]
!--- creation of Virtual access interface 1
Oct 1 20:15:20.935: Vi1 VTEMPLATE: Reuse Vi1, recycle queue size 0
Oct 1 20:15:20.939: Vi1 VTEMPLATE: Set default settings with ip unnumbered
Oct 1 20:15:21.335: Vi1 VTEMPLATE: Hardware address 0000.0c47.7c6c
Oct 1 20:15:21.335: Vi1 PPP: Phase is DOWN, Setup [0 sess, 1 load]
Oct 1 20:15:21.339: Vi1 VTEMPLATE: Has a new cloneblk vtemplate,
now it has vtemplate
!--- Banner: Cloning is in progress on virtual access interface 1
Oct 1 20:15:21.347: Vi1 VTEMPLATE: ******** CLONE VACCESS1 *************
Oct 1 20:15:21.351: Vi1 VTEMPLATE: Clone from Virtual-Template1
!--- The following configuration of Virtual-template is cloned to the
!--- Virtual-access interface.
interface Virtual-Access1
default ip address
no ip address
encap ppp
ip unnumbered Loopback0
no ip unnumbered Loopback0
ip addr 192.168.0.2 255.255.255.0
no ip add
ip unnumbered lo 0
ip add 192.168.0.2 255.255.255.0
ip add 192.168.1.2 255.255.255.0
no ip add
ip unnumbered lo 0
end
Oct 1 20:15:21.367: As9 IPCP: Packet buffered while building MLP bundle interface
Oct 1 20:15:22.319: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async9,
changed state to up
Oct 1 20:15:23.267: As9 IPCP: Packet buffered while building MLP bundle interface
Oct 1 20:15:24.447: Vi1 VTEMPLATE: Messages from (un)cloning ...
192.168.0.0 overlaps with Loopback0
Oct 1 20:15:24.823: Vi1 VTEMPLATE: Messages from (un)cloning ...
192.168.0.0 overlaps with Loopback0
Oct 1 20:15:24.835: %LINK-3-UPDOWN: Interface Virtual-Access1,
changed state to up
Oct 1 20:15:24.843: Vi1 PPP: Treating connection as a dedicated line
Oct 1 20:15:24.847: Vi1 PPP: Phase is ESTABLISHING, Active Open [0 sess, 1 load]
Oct 1 20:15:24.851: Vi1 LCP: O CONFREQ [Closed] id 1 len 29
Oct 1 20:15:24.855: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:15:24.859: Vi1 LCP: MagicNumber 0x078F3560 (0x0506078F3560)
Oct 1 20:15:24.859: Vi1 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:15:24.863: Vi1 LCP: EndpointDisc 1 Router1 (0x130A01526F7574657231)
Oct 1 20:15:24.879: Vi1 PPP: Phase is UP [0 sess, 1 load]
Oct 1 20:15:24.883: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10
Oct 1 20:15:24.883: Vi1 IPCP: Address 192.168.0.2 (0x0306C0A80002)
! -- Asynchrornous interface 9 is added to the Virtual access interface 1
!--- and the name of the bundle is Router2.
Oct 1 20:15:24.891: Vi1 MLP: Added first link As9 to bundle Router2
Oct 1 20:15:24.891: Vi1 PPP: Pending ncpQ size is 2
Oct 1 20:15:24.895: As9 IPCP: Redirect packet to Vi1
Oct 1 20:15:24.895: Vi1 IPCP: I CONFREQ [REQsent] id 1 len 10
Oct 1 20:15:24.899: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 1 20:15:24.903: Vi1 IPCP: O CONFACK [REQsent] id 1 len 10
Oct 1 20:15:24.907: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 1 20:15:24.911: As9 IPCP: Redirect packet to Vi1
Oct 1 20:15:24.915: Vi1 IPCP: I CONFREQ [ACKsent] id 2 len 10
Oct 1 20:15:24.919: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 1 20:15:24.919: Vi1 IPCP: O CONFACK [ACKsent] id 2 len 10
Oct 1 20:15:24.923: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 1 20:15:25.007: Vi1 IPCP: I CONFACK [ACKsent] id 1 len 10
!--- IP address of virtual bundle was previously obtained from the loopback
!--- interface.
Oct 1 20:15:25.011: Vi1 IPCP: Address 192.168.0.2 (0x0306C0A80002)
Oct 1 20:15:25.015: Vi1 IPCP: State is Open
!--- Adds route for virtual bundle to routing table to reach the remote router.
Oct 1 20:15:25.039: Vi1 IPCP: Install route to 192.168.0.1
Oct 1 20:15:25.947: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
Oct 1 20:15:31.199: %OSPF-5-ADJCHG: Process 1, Nbr 192.168.0.1 on Virtual-Access1 from
LOADING to FULL, Loading Done
Oct 1 20:18:01.439: As10 LCP: I CONFREQ [Closed] id 61 len 39
Oct 1 20:18:01.443: As10 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:18:01.447: As10 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:18:01.451: As10 LCP: MagicNumber 0x57DA0D94 (0x050657DA0D94)
Oct 1 20:18:01.451: As10 LCP: PFC (0x0702)
Oct 1 20:18:01.455: As10 LCP: ACFC (0x0802)
Oct 1 20:18:01.455: As10 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:18:01.459: As10 LCP: EndpointDisc 1 Router2 (0x130A01526F7574657232)
Oct 1 20:18:01.463: As10 LCP: Lower layer not up, Fast Starting
Oct 1 20:18:01.467: As10 PPP: Treating connection as a dedicated line
Oct 1 20:18:01.467: As10 PPP: Phase is ESTABLISHING, Active Open [0 sess, 0 load]
Oct 1 20:18:01.475: As10 LCP: O CONFREQ [Closed] id 30 len 39
Oct 1 20:18:01.475: As10 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:18:01.479: As10 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:18:01.483: As10 LCP: MagicNumber 0x0791992D (0x05060791992D)
Oct 1 20:18:01.483: As10 LCP: PFC (0x0702)
Oct 1 20:18:01.487: As10 LCP: ACFC (0x0802)
Oct 1 20:18:01.491: As10 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:18:01.491: As10 LCP: EndpointDisc 1 Router1 (0x130A01526F7574657231)
Oct 1 20:18:01.499: As10 LCP: O CONFACK [REQsent] id 61 len 39
Oct 1 20:18:01.503: As10 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:18:01.507: As10 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:18:01.507: As10 LCP: MagicNumber 0x57DA0D94 (0x050657DA0D94)
Oct 1 20:18:01.511: As10 LCP: PFC (0x0702)
Oct 1 20:18:01.511: As10 LCP: ACFC (0x0802)
Oct 1 20:18:01.515: As10 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:18:01.519: As10 LCP: EndpointDisc 1 Router2 (0x130A01526F7574657232)
Oct 1 20:18:01.703: As10 LCP: I CONFACK [ACKsent] id 30 len 39
Oct 1 20:18:01.703: As10 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 1 20:18:01.707: As10 LCP: AuthProto CHAP (0x0305C22305)
Oct 1 20:18:01.711: As10 LCP: MagicNumber 0x0791992D (0x05060791992D)
Oct 1 20:18:01.715: As10 LCP: PFC (0x0702)
Oct 1 20:18:01.715: As10 LCP: ACFC (0x0802)
Oct 1 20:18:01.719: As10 LCP: MRRU 1524 (0x110405F4)
Oct 1 20:18:01.723: As10 LCP: EndpointDisc 1 Router1 (0x130A01526F7574657231)
Oct 1 20:18:01.723: As10 LCP: State is Open
Oct 1 20:18:01.727: As10 PPP: Phase is AUTHENTICATING, by both [0 sess, 0 load]
Oct 1 20:18:01.731: As10 CHAP: O CHALLENGE id 25 len 28 from "Router1"
Oct 1 20:18:01.743: As10 CHAP: I CHALLENGE id 30 len 28 from "Router2"
Oct 1 20:18:01.755: As10 CHAP: O RESPONSE id 30 len 28 from "Router1"
Oct 1 20:18:01.851: As10 CHAP: I RESPONSE id 25 len 28 from "Router2"
Oct 1 20:18:01.867: As10 CHAP: O SUCCESS id 25 len 4
Oct 1 20:18:01.879: As10 CHAP: I SUCCESS id 30 len 4
Oct 1 20:18:01.879: As10 PPP: Phase is VIRTUALIZED [0 sess, 0 load]
Oct 1 20:18:01.891: Vi1 MLP: Added link As10 to bundle Router2
Oct 1 20:18:02.899: %LINEPROTO-5-UPDOWN: Line protocol on Interface Async10,
changed state to up
Router1#
Router2#debug ppp negotiation
PPP protocol negotiation debugging is on
Router2#debug ppp multilink events
Multilink events debugging is on
Router2#debug dialer
Dial on demand events debugging is on
Router2#show debug
Dial on demand:
Dial on demand events debugging is on
PPP:
PPP protocol negotiation debugging is on
Multilink events debugging is on
Oct 2 20:15:07.442: %SYS-5-CONFIG_I: Configured from console by console
Oct 2 20:15:08.038: %LINK-3-UPDOWN: Interface Dialer3, changed state to up
Oct 2 20:15:08.046: Se3 DDR: rotor dialout [priority]
!--- Dialing Reason
Oct 2 20:15:08.050: Se3 DDR: Dialing cause ip (s=192.168.0.1, d=224.0.0.5)
!--- Number being dialed
Oct 2 20:15:08.054: Se3 DDR: Attempting to dial 30116
Oct 2 20:15:08.058: CHAT3: Attempting async line dialer script
!--- Using chat script "test" for dialout
test & System script: none
Oct 2 20:15:08.066: CHAT3: process started
Oct 2 20:15:08.070: CHAT3: Asserting DTR
Oct 2 20:15:08.070: CHAT3: Chat script test started
!--- Call being established; note the time elapsed for call setup.
Oct 2 20:15:35.814: CHAT3: Chat script test finished, status = Success
Oct 2 20:15:35.830: Di3 IPCP: Install route to 192.168.0.2
! -- Physical Layer (Serial Interface) is up.
!--- Only now can PPP negotiation begin.
Oct 2 20:15:37.818: %LINK-3-UPDOWN: Interface Serial3, changed state to up
Oct 2 20:15:37.822: Se3 DDR: Dialer statechange to up
Oct 2 20:15:37.822: Se3 DDR: Dialer call has been placed
!--- PPP negotiation begins
Oct 2 20:15:37.826: Se3 PPP: Treating connection as a callout
!--- PPP Phase is ESTABLISHING. LCP negotiation will now occur
Oct 2 20:15:37.826: Se3 PPP: Phase is ESTABLISHING, Active Open
[0 sess, 0 load]
!--- Outgoing CONFREQ with Field ID 81
Oct 2 20:15:37.834: Se3 LCP: O CONFREQ [Closed] id 81 len 39
Oct 2 20:15:37.838: Se3 LCP: ACCM 0x000A0000 (0x0206000A0000)
!--- This router is requesting:
! -- Option: Authentication Protocol, Value: CHAP
! -- Option: MagicNumber (used to detect loopbacks and is always sent)
Oct 2 20:15:37.838: Se3 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:37.842: Se3 LCP: MagicNumber 0x57D7985D (0x050657D7985D)
Oct 2 20:15:37.846: Se3 LCP: PFC (0x0702)
Oct 2 20:15:37.846: Se3 LCP: ACFC (0x0802)
Router2#show debug
Dial on demand:
Dial on demand events debugging is on
PPP:
PPP protocol negotiation debugging is on
Multilink events debugging is on
Oct 2 20:15:07.442: %SYS-5-CONFIG_I: Configured from console by console
Oct 2 20:15:08.038: %LINK-3-UPDOWN: Interface Dialer3, changed state to up
Oct 2 20:15:08.046: Se3 DDR: rotor dialout [priority]
!--- Dialing Reason
Oct 2 20:15:08.050: Se3 DDR: Dialing cause ip (s=192.168.0.1, d=224.0.0.5)
!--- Number being dialed
Oct 2 20:15:08.054: Se3 DDR: Attempting to dial 30116
Oct 2 20:15:08.058: CHAT3: Attempting async line dialer script
!--- Using chat script "test" for dialout
Oct 2 20:15:08.058: CHAT3: Dialing using Modem script:
test & System script: none
Oct 2 20:15:08.066: CHAT3: process started
Oct 2 20:15:08.070: CHAT3: Asserting DTR
Oct 2 20:15:08.070: CHAT3: Chat script test started
!--- Call being established; note the time elapsed for call setup.
Oct 2 20:15:35.814: CHAT3: Chat script test finished, status = Success
Oct 2 20:15:35.830: Di3 IPCP: Install route to 192.168.0.2
! -- Physical Layer (Serial Interface) is up.
!--- Only now can PPP negotiation begin.
Oct 2 20:15:37.818: %LINK-3-UPDOWN: Interface Serial3, changed state to up
Oct 2 20:15:37.822: Se3 DDR: Dialer statechange to up
Oct 2 20:15:37.822: Se3 DDR: Dialer call has been placed
Oct 2 20:15:37.826: Se3 PPP: Treating connection as a callout
!--- PPP Phase is ESTABLISHING. LCP negotiation will now occur
Oct 2 20:15:37.826: Se3 PPP: Phase is ESTABLISHING, Active Open
[0 sess, 0 load]
!--- Outgoing CONFREQ with Field ID 81
Oct 2 20:15:37.834: Se3 LCP: O CONFREQ [Closed] id 81 len 39
Oct 2 20:15:37.838: Se3 LCP: ACCM 0x000A0000 (0x0206000A0000)
!--- This router is requesting:
! -- Option: Authentication Protocol, Value: CHAP
! -- Option: MagicNumber (used to detect loopbacks and is always sent)
Oct 2 20:15:37.838: Se3 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:37.842: Se3 LCP: MagicNumber 0x57D7985D (0x050657D7985D)
Oct 2 20:15:37.846: Se3 LCP: PFC (0x0702)
Oct 2 20:15:37.846: Se3 LCP: ACFC (0x0802)
! -- Negotiate Maximum Receive Reconstructed Unit (MRRU)
! -- MRRU is the maximum packet size this end will reconstruct
Oct 2 20:15:37.850: Se3 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:15:37.854: Se3 LCP: EndpointDisc 1 Router2
(0x130A01526F7574657232)
! -- Incoming CONFREQ. ID field is 52
Oct 2 20:15:38.162: Se3 LCP: I CONFREQ [REQsent] id 52 len 39
Oct 2 20:15:38.166: Se3 LCP: ACCM 0x000A0000 (0x0206000A0000)
! -- The peer has requested:
! -- Option: Authentication Protocol, Value: CHAP
! -- Option: MagicNumber (used to detect loopbacks and is always sent)
Oct 2 20:15:38.166: Se3 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:38.170: Se3 LCP: MagicNumber 0x078F2456 (0x0506078F2456)
Oct 2 20:15:38.174: Se3 LCP: PFC (0x0702)
Oct 2 20:15:38.174: Se3 LCP: ACFC (0x0802)
Oct 2 20:15:38.178: Se3 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:15:38.182: Se3 LCP: EndpointDisc 1 Router1
(0x130A01526F7574657231)
! -- Outgoing CONFACK for message with Field ID 52
Oct 2 20:15:38.186: Se3 LCP: O CONFACK [REQsent] id 52 len 39
Oct 2 20:15:38.190: Se3 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:15:38.194: Se3 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:38.198: Se3 LCP: MagicNumber 0x078F2456 (0x0506078F2456)
Oct 2 20:15:38.198: Se3 LCP: PFC (0x0702)
Oct 2 20:15:38.202: Se3 LCP: ACFC (0x0802)
Oct 2 20:15:38.202: Se3 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:15:38.206: Se3 LCP: EndpointDisc 1 Router1
(0x130A01526F7574657231)
! -- Incoming CONFACK for message with Field ID 81
Oct 2 20:15:38.214: Se3 LCP: I CONFACK [ACKsent] id 81 len 39
Oct 2 20:15:38.214: Se3 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:15:38.218: Se3 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:38.222: Se3 LCP: MagicNumber 0x57D7985D (0x050657D7985D)
Oct 2 20:15:38.222: Se3 LCP: PFC (0x0702)
Oct 2 20:15:38.226: Se3 LCP: ACFC (0x0802)
! -- Both sides have CONFACKed the parameters
! -- MRRU of 1524 bytes and the Endpoint Discriminator have been negotiated
Oct 2 20:15:38.230: Se3 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:15:38.230: Se3 LCP: EndpointDisc 1 Router2 (0x130A01526F7574657232
! -- LCP negotiation complete and LCP state goes to Open
Oct 2 20:15:38.234: Se3 LCP: State is Open
! -- PPP Phase is AUTHENTICATING. PPP Authentication occurs now
! -- Two-way authentication will be performed (indicated by the both keyword)
Oct 2 20:15:38.238: Se3 PPP: Phase is AUTHENTICATING, by both [0 sess, 0 load]
! -- Outgoing CHAP Challenge.
! -- In LCP we had agreed upon CHAP as the authentication protocol
Oct 2 20:15:38.238: Se3 CHAP: O CHALLENGE id 40 len 28 from "Router2"
! -- Incoming Challenge from peer
Oct 2 20:15:38.398: Se3 CHAP: I CHALLENGE id 45 len 28 from "Router1"
! -- Incoming response from peer
Oct 2 20:15:38.402: Se3 CHAP: I RESPONSE id 40 len 28 from "Router1"
! -- Outgoing Response
Oct 2 20:15:38.410: Se3 CHAP: O RESPONSE id 45 len 28 from "Router2"
! -- CHAP authentication successful
Oct 2 20:15:38.418: Se3 CHAP: O SUCCESS id 40 len 4
Oct 2 20:15:38.538: Se3 CHAP: I SUCCESS id 45 len 4
Oct 2 20:15:38.542: Se3 MLP: Request add link to bundle
! -- Virtualize Se3
! -- Virtual Access interface will represent the MP bundle
Oct 2 20:15:38.542: Se3 PPP: Phase is VIRTUALIZED [0 sess, 1 load]
Oct 2 20:15:38.546: Se3 MLP: Adding link to bundle
Oct 2 20:15:38.550: Vi1 PPP: Phase is DOWN, Setup [0 sess, 0 load]
Oct 2 20:15:38.558: Vi1 PPP: No remote authentication for call-out
Oct 2 20:15:38.566: Vi1 MLP: Added to huntgroup Di3
Oct 2 20:15:38.570: Vi1 MLP: Clone from Di3
Oct 2 20:15:38.574: %LINK-3-UPDOWN: Interface Virtual-Access1,
changed state to up
Oct 2 20:15:38.578: Vi1 DDR: Dialer statechange to up
! -- Virtual Access Interface is up
! -- Negotiate LCP and PPP parameters for Virtual-Access Interface
Oct 2 20:15:38.582: Vi1 DDR: Dialer call has been placed
Oct 2 20:15:38.586: Vi1 PPP: Treating connection as a callout
Oct 2 20:15:38.586: Vi1 PPP: Phase is ESTABLISHING, Active Open
[0 sess, 0 load]
Oct 2 20:15:38.594: Vi1 LCP: O CONFREQ [Closed] id 1 len 29
Oct 2 20:15:38.594: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:15:38.598: Vi1 LCP: MagicNumber 0x57D79B57 (0x050657D79B57)
Oct 2 20:15:38.602: Vi1 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:15:38.606: Vi1 LCP: EndpointDisc 1 Router2
(0x130A01526F7574657232
Oct 2 20:15:38.614: Vi1 PPP: Phase is UP [0 sess, 0 load]
Oct 2 20:15:38.618: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10
Oct 2 20:15:38.622: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
! -- First multilink connection is brought up in the virtual access interface
Oct 2 20:15:38.626: Vi1 MLP: Added first link Se3 to bundle Router1
Oct 2 20:15:38.630: Di3 IPCP: Remove route to 192.168.0.2
Oct 2 20:15:39.542: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial3,
changed state to up
Oct 2 20:15:39.614: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access1, changed state to up
Oct 2 20:15:40.614: Vi1 IPCP: TIMEout: State REQsent
Oct 2 20:15:40.618: Vi1 IPCP: O CONFREQ [REQsent] id 2 len 10
Oct 2 20:15:40.618: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 2 20:15:41.046: Vi1 MLP: Load (1) above threshold in bundle Router1
Oct 2 20:15:41.046: Se2 DDR: rotor dialout [priority]
Oct 2 20:15:41.050: Se2 DDR: Attempting to dial 30116
Oct 2 20:15:41.054: CHAT2: Attempting async line dialer script
Oct 2 20:15:41.054: CHAT2: Dialing using Modem script:
test & System script: none
Oct 2 20:15:41.062: CHAT2: process started
Oct 2 20:15:41.066: CHAT2: Asserting DTR
Oct 2 20:15:41.066: CHAT2: Chat script test started
Oct 2 20:15:42.506: Vi1 IPCP: I CONFREQ [REQsent] id 1 len 10
Oct 2 20:15:42.510: Vi1 IPCP: Address 192.168.0.2 (0x0306C0A80002)
Oct 2 20:15:42.514: Vi1 IPCP: O CONFACK [REQsent] id 1 len 10
Oct 2 20:15:42.518: Vi1 IPCP: Address 192.168.0.2 (0x0306C0A80002)
Oct 2 20:15:42.530: Vi1 IPCP: I CONFACK [ACKsent] id 1 len 10
Oct 2 20:15:42.534: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 2 20:15:42.538: Vi1 IPCP: ID 1 didn't match 2, discarding packet
Oct 2 20:15:42.546: Vi1 IPCP: I CONFACK [ACKsent] id 2 len 10
Oct 2 20:15:42.550: Vi1 IPCP: Address 192.168.0.1 (0x0306C0A80001)
Oct 2 20:15:42.554: Vi1 IPCP: State is Open
Oct 2 20:15:42.562: Vi1 DDR: dialer protocol up
Oct 2 20:15:42.570: Vi1 DDR: Call connected, 4 packets unqueued,
4 transmitted 0 discarded
! -- Adds route for virtual bundle to routing table to reach the remote router
Oct 2 20:15:42.582: Di3 IPCP: Install route to 192.168.0.2
Oct 2 20:15:48.714: %OSPF-5-ADJCHG: Process 1, Nbr 192.168.0.2 on Dialer3
from LOADING to FULL, Loading Done
Oct 2 20:17:41.070: CHAT2: Chat script test finished, status = Connection timed
out; remote host not responding
Oct 2 20:17:41.074: Se2 DDR: disconnecting call
Oct 2 20:17:56.074: Se2 DDR: re-enable timeout
Oct 2 20:17:56.074: Se2 DDR: Attempting to dial 30114
Oct 2 20:17:56.078: CHAT2: Attempting async line dialer script
Oct 2 20:17:56.078: CHAT2: Dialing using Modem script: test & System script:
none
Oct 2 20:17:56.086: CHAT2: process started
Oct 2 20:17:56.090: CHAT2: Asserting DTR
Oct 2 20:17:56.090: CHAT2: Chat script test started
! -- Call is being established; note the time elapsed for call setup
Oct 2 20:18:16.890: CHAT2: Chat script test finished, status = Success
Oct 2 20:18:18.894: %LINK-3-UPDOWN: Interface Serial2, changed state to up
Oct 2 20:18:18.898: Se2 DDR: Dialer statechange to up
Oct 2 20:18:18.898: Se2 DDR: Dialer call has been placed
! -- PPP negotiation begins
Oct 2 20:18:18.902: Se2 PPP: Treating connection as a callout
Oct 2 20:18:18.906: Se2 PPP: Phase is ESTABLISHING, Active Open
[0 sess, 0 load]
! -- LCP negotiation begins; Multilink parameters are also negotiated
Oct 2 20:18:18.910: Se2 LCP: O CONFREQ [Closed] id 61 len 39
Oct 2 20:18:18.914: Se2 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:18:18.918: Se2 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:18:18.918: Se2 LCP: MagicNumber 0x57DA0D94 (0x050657DA0D94)
Oct 2 20:18:18.922: Se2 LCP: PFC (0x0702)
Oct 2 20:18:18.926: Se2 LCP: ACFC (0x0802)
! -- Negotiate Maximum Receive Reconstructed Unit (MRRU)
! -- MRRU is the maximum packet size this end will reconstruct
Oct 2 20:18:18.926: Se2 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:18:18.930: Se2 LCP: EndpointDisc 1 Router2
(0x130A01526F7574657232)
Oct 2 20:18:19.142: Se2 LCP: I CONFREQ [REQsent] id 30 len 39
Oct 2 20:18:19.146: Se2 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:18:19.146: Se2 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:18:19.150: Se2 LCP: MagicNumber 0x0791992D (0x05060791992D)
Oct 2 20:18:19.154: Se2 LCP: PFC (0x0702)
Oct 2 20:18:19.154: Se2 LCP: ACFC (0x0802)
Oct 2 20:18:19.158: Se2 LCP: MRRU 1524 (0x110405F4)
(0x130A01526F7574657231)
Oct 2 20:18:19.170: Se2 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:18:19.174: Se2 LCP: MagicNumber 0x0791992D (0x05060791992D)
Oct 2 20:18:19.178: Se2 LCP: ACFC (0x0802)
Oct 2 20:18:19.182: Se2 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:18:19.186: Se2 LCP: EndpointDisc 1 Router1
(0x130A01526F7574657231)
Oct 2 20:18:19.194: Se2 LCP: I CONFACK [ACKsent] id 61 len 39
Oct 2 20:18:19.198: Se2 LCP: ACCM 0x000A0000 (0x0206000A0000)
Oct 2 20:18:19.198: Se2 LCP: AuthProto CHAP (0x0305C22305)
Oct 2 20:18:19.202: Se2 LCP: MagicNumber 0x57DA0D94 (0x050657DA0D94)
Oct 2 20:18:19.206: Se2 LCP: PFC (0x0702)
Oct 2 20:18:19.206: Se2 LCP: ACFC (0x0802)
Oct 2 20:18:19.210: Se2 LCP: MRRU 1524 (0x110405F4)
Oct 2 20:18:19.214: Se2 LCP: EndpointDisc 1 Router2
(0x130A01526F7574657232)
Oct 2 20:18:19.214: Se2 LCP: State is Open
Oct 2 20:18:19.218: Se2 PPP: Phase is AUTHENTICATING, by both [0 sess, 0 load]
Oct 2 20:18:19.222: Se2 CHAP: O CHALLENGE id 30 len 28 from "Router2"
Oct 2 20:18:19.358: Se2 CHAP: I CHALLENGE id 25 len 28 from "Router1"
Oct 2 20:18:19.362: Se2 CHAP: O RESPONSE id 25 len 28 from "Router2"
Oct 2 20:18:19.382: Se2 CHAP: I RESPONSE id 30 len 28 from "Router1"
Oct 2 20:18:19.390: Se2 CHAP: O SUCCESS id 30 len 4
Oct 2 20:18:19.482: Se2 CHAP: I SUCCESS id 25 len 4
Oct 2 20:18:19.486: Se2 MLP: Request add link to bundle
Oct 2 20:18:19.486: Se2 PPP: Phase is VIRTUALIZED [0 sess, 0 load]
!--- Virtualize Se2
!--- Virtual Access interface will represent the MP bundle
Oct 2 20:18:19.490: Se2 MLP: Adding link to bundle
!--- Second multilink connection is virtualized and added to Virtual
!--- access interface.
Oct 2 20:18:19.494: Se2 IPCP: Route to 192.168.0.2 still needed by Vi1
Oct 2 20:18:19.498: DDR: MLP bundle, 0 packets unqueued and discarded
Oct 2 20:18:19.498: Vi1 MLP: Added link Se2 to bundle Router1
Oct 2 20:18:20.482: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial2,
changed state to up
Troubleshooting Commands
Certain show commands are supported by the Output Interpreter Tool ( registered customers only) , which allows
you to view an analysis of show command output.
Note:Before issuing debug commands, please see Important Information on Debug Commands.
debug ppp negotiation - To see if a client is passing PPP negotiation; this commnad is used to check
for address negotiation.
debug ppp authentication - To see if a client is passing authentication. If you are using a Cisco IOS
Software Release prior to 11.2, use the debug ppp chap command instead.
debug ppp error - To display protocol errors and error statistics associated with PPP connection
negotiation and operation.
debug vtemplate - To display the Virtual Template cloning to form a Virtual Access interface.
debug ppp multilink events - To see PPP multilink events debugging. Displays information about
events affecting multilink groups.
debug dialer - To display debugging information about the packets received on a dialer interface.
show caller - Displays statistics or debug information for connections.
show dialer - Displays general diagnostic information for interfaces configured for DDR.
show caller user- Displays List of which user is using which modem port.
show ppp multilink- To see the members of the multilink bundle.
