|
This chapter contains the following information about integrated Digital Subscriber Line (DSL) access to Multiprotocol Label Switching (MPLS) Virtual Private Network (VPN):
This section contains the following troubleshooting topics:
Figure 3-1 shows the topology associated with a VPN-capable service provider's MPLS backbone. In this scenario, you should assume that the customer has outsourced all remote access operations to its service provider.
For reminders on using the command line interface for viewing debug output, refer to "Initiating and Viewing Command Output" section.
Table 3-1 corresponds to Figure 3-1, providing a cross-reference to the debugging topics contained in this section. The number shown in column one of this table corresponds to the element number shown in the call flow part of Figure 3-1.
Element Number Shown in Figure 3-1: | Related Troubleshooting Topic(s): |
---|---|
Line 1: RFC 1483 permanent virtual circuit (PVC) connected between DSL router and provider edge (PE) device. | |
Line 2: (Depends on setup) Dynamic Host Configuration Protocol (DHCP) server provides address assignment. Note The address assignment applies only if the service provider intends to relay DHCP requests from the customer premises equipment (CPE) to a far-end DHCP server. This line is not necessary if an alternative address assignment mechanism is used, such as a statically assigned address block for each CPE. |
If RFC 1483 PVC does not connect, use the following debug commands in privileged EXEC mode:
The debug atm packet command is used to ensure that you are receiving RFC 1483 routed protocol data units (PDUs). An RFC 1483 routed PDU has an 8 byte header. The first 3 bytes are considered the Logical Link Control (LLC) portion [0xAA-AA-03]. The next 3 bytes are the Organizationally Unique Identifier (OUI) portion [0x00-00-00]. The last 2 bytes are the EtherType [0x08-00]. The packet payload follows the header. Example 3-1 shows an example of an RFC 1483 routed PDU and Example 3-2 shows, for comparison, the format of a bridged (802.3-specific) RFC 1483 PDU. Cisco IOS typically does not transmit (but is able to receive) the LAN FCS, CBOS does transmit the LAN FCS, and certain vendors include the LAN FCS.
LLC (bytes 1 - 3) - [0xAA-AA-03]
OUI (bytes 4 - 6) - [0x00-00-00]
EtherType (bytes 7 - 8) - [0x08-00]
payload
LLC (bytes 1 - 3) - [0xAA-AA-03]
OUI (bytes 4 - 6) - [0x00-08-C2]
PID (bytes 7 - 8) - [0x00-07] or [0x00-01] if LAN FCS is needed / included
PAD (bytes 9-10) - [0x00 - 00]
Standard MAC header
Payload
LAN FCS (optional)
Example 3-3 provides a sample of the output that results from implementing the debug atm packet command.
nrp1bot# debug atm packet
ATM packets debugging is on
Displaying all ATM packets
nrp1bot# sh debug
Generic ATM: ATM packets debugging is on
[PE]
May 3 16:29:34.713: ATM0/0/0.135(I):
VCD:0x5 VPI:0xA VCI:0x23 Type:0x0 SAP:AAAA CTL:03 OUI:000000 TYPE:0800
Length:0x28
May 3 16:29:34.713: 4500 001C 001F 0000 3F01 65B7 0A01 0101 0A01 0109 0800
F7EC 0000 0013
May 3 16:29:34.713:
Example 3-4 shows sample output from the debug ip command. Always combine the debug ip packet detail command with an access list to prevent overloading the router.
nrp1bot# debug ip packet
IP packet debugging is on
nrp1bot# sh debug
Generic IP: IP packet debugging is on
[PE]
DSL7200# ping 209.165.200.224
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 209.165.200.224, timeout is 2 seconds:
*Oct 4 20:47:57.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, sending
*Oct 4 20:47:57.781: ICMP type=8, code=0
*Oct 4 20:47:57.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, encapsulation
failed
*Oct 4 20:47:57.785: ICMP type=8, code=0.
*Oct 4 20:47:59.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, sending
*Oct 4 20:47:59.781: ICMP type=8, code=0
*Oct 4 20:47:59.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, encapsulation
failed
If a Layer 3 address (for example an IP address) cannot be mapped to a corresponding Layer 2 address, Cisco IOS marks an encapsulation failure on the packet and drops it. So on a multipoint interface, a static map is needed to the next hop or a dynamic map (learned through an ATM Inverse Address Resolution Protocol transaction) to forward packets.
In the case of a static map, you can confirm the configuration of the map statements with a show atm map command.
Note IP packet debugging and Asynchronous Transfer Mode (ATM) packet debugging only show packets and cells that are process switched. On MPLS-enabledlabel edge router (LER) and label switch router (LSR) routers, Cisco Express Forwarding (CEF) is configured globally. Hence to view the output for all packets transiting an interface, you can configure the no ip route-cache cef command on the ATM interface to display the debug output. |
Note Remember to reenable the ip route-cache cef command on the interface after completing your debugging. |
If address assignment fails, use the following debug commands in privileged EXEC mode:
Example 3-5 provides a sample of the debug command output that results from these commands.
nrp1bot# sh debug
DHCP server packet debugging is on.
DHCP server event debugging is on.
nrp1bot#
nrp1bot#
May 18 16:43:02.485: DHCPD: setting giaddr to 10.1.1.5.
May 18 16:43:02.485: DHCPD: BOOTREQUEST from 0100.10a4.facc.aa forwarded to 172.29.51.239.
May 18 16:43:02.489: DHCPD: BOOTREQUEST from 0100.10a4.facc.aa forwarded to 172.29.51.239.
May 18 16:43:02.561: DHCPD: setting giaddr to 10.1.1.5.
May 18 16:43:02.561: DHCPD: BOOTREQUEST from 0100.10a4.facc.aa forwarded to 172.29.51.239.
May 18 16:43:02.565: DHCPD: BOOTREQUEST from 0100.10a4.facc.aa forwarded to 172.29.51.239.
May 18 16:43:02.665: hardware_address(): hardware address specified
May 18 16:43:02.665: hardware_address(): chaddr in pak. = 616874D8
May 18 16:43:02.665: DHCPD: forwarding BOOTREPLY to client 0010.a4fa.ccaa.
May 18 16:43:02.665: DHCPD: Forwarding reply on numbered intf
May 18 16:43:02.665: DHCPD: creating ARP entry (10.1.1.2, 0010.a4fa.ccaa).
May 18 16:43:02.665: DHCPD: SIOCSARP ioctl failed (error 22).
May 18 16:43:02.665: DHCPD: broadcasting BOOTREPLY to client 0010.a4fa.ccaa.
nrp1bot#
The following show commands are useful in debugging RFC 1483:
The following examples show the output from these show commands.
nrp1bot# sh ip route vrf vpn100
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.29.0.0/24 is subnetted, 1 subnets
B 172.29.51.0 [200/0] via 10.1.1.4, 7w0d
10.0.0.0/32 is subnetted, 2 subnets
C 10.1.1.10 is directly connected, Loopback100
B 10.1.1.9 [200/0] via 10.1.1.4, 7w0d
ATM0/0/0.2033 is up, line protocol is up
Hardware is ATM-SAR
Description: 1cardPPPoA [20/33]8/0/1->6260->677[1/1]
MTU 4470 bytes, BW 156250 Kbit, DLY 80 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation ATM
100254 packets input, 1535132 bytes
1313957 packets output,22087983 bytes
0 OAM cells input, 0 OAM cells output
nrp1bot# sh int atm 0/0/0
ATM0/0/0 is up, line protocol is up
Hardware is ATM-SAR
MTU 4470 bytes, sub MTU 4470, BW 156250 Kbit, DLY 80 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation ATM, loopback not supported
Keepalive not supported
Encapsulation(s): AAL5, PVC mode
2047 maximum active VCs, 2 current VCCs
VC idle disconnect time: 300 seconds
Last input 9w5d, output 00:00:00, output hang never
Last clearing of "show interface" counters never
Queueing strategy: fifo
Output queue 0/80, 7 drops; input queue 0/1000, 0 drops
5 minute input rate 0 bits/sec, 0 packets/sec
5 minute output rate 0 bits/sec, 0 packets/sec
56031 packets input, 1943197 bytes, 0 no buffer
Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
1315498 packets output, 27477357 bytes, 0 underruns
0 output errors, 0 collisions, 1 interface resets
0 output buffer failures, 0 output buffers swapped out
DSL7200# show atm map
Map list ATM2/0.7pvc15 : PERMANENT
ip 6.6.6.1 maps to VC 15, VPI 3, VCI 32, ATM2/0.7 , broadcast
nrp1bot# sh atm vc
VCD / Peak Avg/Min Burst
Interface Name VPI VCI Type Encaps SC Kbps Kbps Cells Sts
0/0/0.133 3 10 33 PVC SNAP UBR 0 INAC
0/0/0.134 4 10 34 PVC SNAP UBR 0 INAC
0/0/0.135 5 10 35 PVC SNAP UBR 155000 UP
This section contains the following troubleshooting topics:
Routed Bridge Encapsulation (RBE) is used to route RFC1483 ATM Bridged PDUs. The Bridged PDUs are routed by examining the destination IP address within the IP Payload contained within the bridged ethernet frame from a stub-bridged LAN. Bridged IP packets received on an ATM interface configured in routed-bridge mode are routed via an IP header. The interface takes advantage of the characteristics of a stub LAN topology commonly used for DSL access and offers increased performance and flexibility over integrated routing and bridging (IRB).
In Figure 3-2, RBE is configured between the DSL router and the VHG/PE. The DSL router can be set up as a pure bridge or can be set up for IRB, where multiple LAN interfaces are bridged through the bridge group virtual interface (BVI). Each of the DSL routers terminates on a separate point-to-point subinterface on the VHG/PE which is statically configured with a specific VRF. Remote user authentication or authorization is available with Option 82 for DSL routed bridge encapsulation remote access.
RBE treats the VHG/PE subinterface as if it were connected to an Ethernet LAN, but avoids the disadvantages of pure bridging such as broadcast storms, IP hijacking, and ARP spoofing issues. Address management options include static and VRF-aware DHCP servers. Since this architecture is not PPP based, RADIUS accounting cannot be used. Netflow is used for accounting.
For a description of RBE architecture, refer to:
http://www.cisco.com/warp/public/794/routed_bridged_encap.html.
For RBE IOS commands, refer to http://www.cisco.com/univercd/cc/td/doc/product/software/ios122/122sup/122csum/csum2/122cswan/ wsfbrda.htm#1051874
For platform-specific overview and configuration information, refer to:
ATM Routed Bridge Encapsulation Feature Overview - Cisco 6400 series:
http://www.cisco.com/univercd/cc/td/doc/product/software/ios120/120newft/120limit/120dc/120dc5/at m_rb.htm
ATM Routed Bridge Encapsulation Feature Overview - Cisco 7200 series:
http://www.cisco.com/univercd/cc/td/doc/product/software/ios121/121newft/121t/121t2/dtatmrbe.htm
For reminders on using the command line interface for viewing debug output, refer to "Initiating and Viewing Command Output" section.
Table 3-2 corresponds to Figure 3-2, providing a cross-reference to the debugging topics contained in this section.
Call Flow Step | Related Troubleshooting Topic(s): |
---|---|
Step 1. RFC 1483 permanent virtual circuit (PVC) connected between DSL router and provider edge (PE) device. | |
Step 2. (Depends on setup) Dynamic Host Configuration Protocol (DHCP) server provides address assignment. Note The address assignment applies only if the service provider intends to relay DHCP requests from the customer premises equipment (CPE) to a far-end DHCP server. This line is not necessary if an alternative address assignment mechanism is used, such as a statically assigned address block for each CPE. |
If RFC 1483 PVC does not connect, use the following debug commands in privileged EXEC mode:
The debug atm packet command is used to ensure that you are receiving RFC 1483 routed protocol data units (PDUs).
An RFC 1483 routed PDU has an 8 byte header. The first 3 bytes are considered the Logical Link Control (LLC) portion [0xAA-AA-03]. The next 3 bytes are the Organizationally Unique Identifier (OUI) portion [0x00-08-C2]. The type of the bridged media is specified by the two octet PID [0x00-07] or [0x00-010. The PID indicates whether the original Frame Check Sequence (FCS) is preserved within the bridged PDU. Padding is added after the PID field to align the user information field of the bridged PDU at a four octet boundary [0x00 - 00]. The packet payload follows the header. Cisco IOS typically does not transmit (but is able to receive) the LAN FCS, CBOS does transmit the LAN FCS, and certain vendors include the LAN FCS.
LLC (bytes 1 - 3) - [0xAA-AA-03]
OUI (bytes 4 - 6) - [0x00-08-C2]
PID (bytes 7 - 8) - [0x00-07] or [0x00-01] if LAN FCS is needed / included
PAD (bytes 9-10) - [0x00 - 00]
Standard MAC header
Payload
LAN FCS (optional)
Example 3-11 provides a sample of the output that results from implementing the debug atm packet command.
nrp1bot# debug atm packet
ATM packets debugging is on
Displaying all ATM packets
nrp1bot# sh debug
Generic ATM: ATM packets debugging is on
[PE]
May 3 16:29:34.713: ATM0/0/0.135(I):
VCD:0x5 VPI:0xA VCI:0x23 Type:0x0 SAP:AAAA CTL:03 OUI:000000 TYPE:0800
Length:0x28
May 3 16:29:34.713: 4500 001C 001F 0000 3F01 65B7 0A01 0101 0A01 0109 0800
F7EC 0000 0013
May 3 16:29:34.713:
Example 3-12 shows sample output from the debug ip command. Always combine the debug ip packet detail command with an access list to prevent overloading the router.
nrp1bot# debug ip packet
IP packet debugging is on
nrp1bot# sh debug
Generic IP: IP packet debugging is on
[PE]
DSL7200# ping 209.165.200.224
Type escape sequence to abort.
Sending 5, 100-byte ICMP Echos to 209.165.200.224, timeout is 2 seconds:
*Oct 4 20:47:57.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, sending
*Oct 4 20:47:57.781: ICMP type=8, code=0
*Oct 4 20:47:57.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, encapsulation
failed
*Oct 4 20:47:57.785: ICMP type=8, code=0.
*Oct 4 20:47:59.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, sending
*Oct 4 20:47:59.781: ICMP type=8, code=0
*Oct 4 20:47:59.781: IP: s=6.6.6.5 (local), d=6.6.6.6 (ATM2/0.8), len 100, encapsulation
failed
If a Layer 3 address (for example an IP address) cannot be mapped to a corresponding Layer 2 address, Cisco IOS marks an encapsulation failure on the packet and drops it. So on a multipoint interface, a static map is needed to the next hop or a dynamic map (learned through an ATM Inverse Address Resolution Protocol transaction) to forward packets.
In the case of a static map, you can confirm the configuration of the map statements with a show atm map command.
Note IP packet debugging and Asynchronous Transfer Mode (ATM) packet debugging only show packets and cells that are process switched. On MPLS-enabledlabel edge router (LER) and label switch router (LSR) routers, Cisco Express Forwarding (CEF) is configured globally. Hence to view the output for all packets transiting an interface, you can configure the no ip route-cache cef command on the ATM interface to display the debug output. |
Note Remember to reenable the ip route-cache cef command on the interface after completing your debugging. |
If address assignment fails, use the following debug commands in privileged EXEC mode:
Example 3-13 provides a sample of the debug command output that results from this command.
nrp1bot# sh debug
DHCPD: relay binding created for client 0100.10a4.f9c2.53.
DHCPD: setting giaddr to 25.0.13.29.
DHCPD: adding relay information option.
DHCPD: BOOTREQUEST from 0100.10a4.f9c2.53 forwarded to 10.15.61.63.
DHCPD: Giaddr from server-id-override suboption 25.0.13.29
DHCPD: forwarding BOOTREPLY to client 0010.a4f9.c253.
outbound IF index = 4
outbound IF sub-index = 1
DHCPD: unnum: broadcasting BOOTREPLY to client 0010.a4f9.c253.
*********************************************************************
RT(red): add 13.0.0.2/32 via 0.0.0.0, static metric [1/0]
outbound IF index = 4
outbound IF sub-index = 1
*********************************************************************rbe
The following show commands are useful in debugging RBE to MPLS VPN integration:
The following examples show the output from these show commands.
nrp1bot# sh ip route vrf red
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
100.0.0.0/32 is subnetted, 3 subnets
B 100.0.0.1 [200/0] via 25.0.13.23, 04:44:23
B 100.0.0.2 [200/0] via 25.0.13.23, 04:44:23
B 100.0.0.3 [200/0] via 25.0.13.23, 04:44:23
10.0.0.0/30 is subnetted, 1 subnets
B 10.10.10.0 [200/0] via 25.0.13.23, 04:44:23
13.0.0.0/32 is subnetted, 1 subnets
S 13.0.0.2 is directly connected, ATM4/0.1
nrp1bot# sh ip arp vrf red
Protocol Address Age (min) Hardware Addr Type Interface
Internet 13.0.0.2 1 0010.a4f9.c253 ARPA ATM4/0.1
ATM0/0/0.2033 is up, line protocol is up
Hardware is ATM-SAR
Description: 1cardPPPoA [20/33]8/0/1->6260->677[1/1]
MTU 4470 bytes, BW 156250 Kbit, DLY 80 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation ATM
100254 packets input, 1535132 bytes
1313957 packets output,22087983 bytes
0 OAM cells input, 0 OAM cells output
nrp1bot# sh int atm 0/0/0
ATM0/0/0 is up, line protocol is up
Hardware is ATM-SAR
MTU 4470 bytes, sub MTU 4470, BW 156250 Kbit, DLY 80 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation ATM, loopback not supported
Keepalive not supported
Encapsulation(s): AAL5, PVC mode
2047 maximum active VCs, 2 current VCCs
VC idle disconnect time: 300 seconds
Last input 9w5d, output 00:00:00, output hang never
Last clearing of "show interface" counters never
Queueing strategy: fifo
Output queue 0/80, 7 drops; input queue 0/1000, 0 drops
5 minute input rate 0 bits/sec, 0 packets/sec
5 minute output rate 0 bits/sec, 0 packets/sec
56031 packets input, 1943197 bytes, 0 no buffer
Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
1315498 packets output, 27477357 bytes, 0 underruns
0 output errors, 0 collisions, 1 interface resets
0 output buffer failures, 0 output buffers swapped out
nrp1bot# sh atm vc
VCD / Peak Avg/Min Burst
Interface Name VPI VCI Type Encaps SC Kbps Kbps Cells Sts
0/0/0.133 3 10 33 PVC SNAP UBR 0 INAC
0/0/0.134 4 10 34 PVC SNAP UBR 0 INAC
0/0/0.135 5 10 35 PVC SNAP UBR 155000 UP
This section contains the following troubleshooting topics:
Figure 3-3 shows the topology associated with a VPN-capable service provider's MPLS backbone. In this scenario, you should assume that the customer has outsourced all remote access operations to its service provider.
For reminders on using the command-line interface for viewing debug command output, refer to the sections of the Remote Access to MPLS VPN Solution Provisioning Guide 1.0 entitled "User Interface Command Modes" and "User Command Modes." This document can be accessed at the following URL:
http://cco/univercd/cc/td/doc/product/vpn/solution/rampls/index.htm
Table 3-3 (below) corresponds to Figure 3-3, providing a cross-reference to the troubleshooting topics associated with the events that occur when the remote user creates a Point-to-Point Protocol over ATM or Ethernet (PPPoX) session over DSL in an attempt to access its corporate network or Internet service provider (ISP).
Event Shown in Figure 3-2: | Related Troubleshooting Topic(s): |
---|---|
Lines1-2: DSL router initiates a PPPoA session or remote user initiates a PPPoE session, and VHG/PE accepts session. | |
Lines 3-4: VHG/PE queries SP RADIUS server and completes the remote user's authentication via RADIUS. | |
Lines 3-4: After successfully completing authentication, the remote user is associated with a specific customer MPLS VPN. | Remote User Is Associated with a Specific Customer MPLS VPN (Step 3 and Step 4[b]) |
Line 5: VHG/PE obtains an IP address for the remote user. |
The DSL router initiates a Point-to-Point Protocol over ATM (PPPoA) session over the DSL access network. If the DSL router cannot initiate a PPPoA session, use the following debug commands in privileged EXEC mode:
Example 3-17 provides a sample of the debug command output that results from these commands.
nrp1bot# debug ppp negotiation
PPP protocol negotiation debugging is on
nrp1bot# debug ppp authentication
PPP authentication debugging is on
nrp1bot# sh debug
PPP:
PPP authentication debugging is on
PPP protocol negotiation debugging is on
nrp1bot#
Jul 2 15:16:01.502: Vi1 LCP: TIMEout: State Listen
Jul 2 15:16:01.502: Vi1 LCP: O CONFREQ [Listen] id 166 len 15
Jul 2 15:16:01.502: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:01.502: Vi1 LCP: MagicNumber 0x121E1573 (0x0506121E1573)
Jul 2 15:16:01.534: Vi1 LCP: I CONFACK [REQsent] id 166 len 15
Jul 2 15:16:01.534: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:01.534: Vi1 LCP: MagicNumber 0x121E1573 (0x0506121E1573)
Jul 2 15:16:02.410: Vi1 LCP: I CONFREQ [ACKrcvd] id 86 len 14
Jul 2 15:16:02.410: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 2 15:16:02.410: Vi1 LCP: MRU 2048 (0x01040800)
Jul 2 15:16:02.410: Vi1 LCP: O CONFACK [ACKrcvd] id 86 len 14
Jul 2 15:16:02.410: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 2 15:16:02.410: Vi1 LCP: MRU 2048 (0x01040800)
Jul 2 15:16:02.410: Vi1 LCP: State is Open
Jul 2 15:16:02.410: Vi1 PPP: Phase is AUTHENTICATING, by this end [0 sess,
0 load]
Jul 2 15:16:02.410: Vi1 CHAP: O CHALLENGE id 158 len 28 from "nrp1bot"
Jul 2 15:16:02.446: Vi1 CHAP: I RESPONSE id 158 len 34 from "1cardpppoa1_1"
Jul 2 15:16:02.458: Vi1 CHAP: O SUCCESS id 158 len 4
Jul 2 15:16:02.462: Vi1 PPP: Idle timeout, dropping connection
Jul 2 15:16:02.462: Vi1 PPP: Phase is TERMINATING [0 sess, 0 load]
Jul 2 15:16:02.466: Vi1 LCP: O TERMREQ [Open] id 167 len 4
Jul 2 15:16:02.494: Vi1 IPCP: LCP not open, discarding packet
Jul 2 15:16:02.498: Vi1 LCP: I TERMACK [TERMsent] id 167 len 4
Jul 2 15:16:02.498: Vi1 LCP: State is Closed
Jul 2 15:16:02.498: Vi1 PPP: Phase is DOWN [0 sess, 0 load]
Jul 2 15:16:02.506: Vi1 PPP: Phase is ESTABLISHING, Passive Open [0 sess, 0
load]
Jul 2 15:16:02.506: Vi1 LCP: State is Listen
Jul 2 15:16:04.506: Vi1 LCP: TIMEout: State Listen
Jul 2 15:16:04.506: Vi1 LCP: O CONFREQ [Listen] id 168 len 15
Jul 2 15:16:04.506: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:04.506: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:06.506: Vi1 LCP: TIMEout: State REQsent
Jul 2 15:16:06.506: Vi1 LCP: O CONFREQ [REQsent] id 169 len 15
Jul 2 15:16:06.506: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:06.506: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:08.506: Vi1 LCP: TIMEout: State REQsent
Jul 2 15:16:08.506: Vi1 LCP: O CONFREQ [REQsent] id 170 len 15
Jul 2 15:16:08.506: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:08.506: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:10.506: Vi1 LCP: TIMEout: State REQsent
Jul 2 15:16:10.506: Vi1 LCP: O CONFREQ [REQsent] id 171 len 15
Jul 2 15:16:10.506: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:10.506: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:12.507: Vi1 LCP: TIMEout: State REQsent
Jul 2 15:16:12.507: Vi1 LCP: O CONFREQ [REQsent] id 172 len 15
Jul 2 15:16:12.507: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:12.507: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:14.415: Vi1 LCP: I CONFREQ [REQsent] id 88 len 14
Jul 2 15:16:14.415: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 2 15:16:14.415: Vi1 LCP: MRU 2048 (0x01040800)
Jul 2 15:16:14.415: Vi1 LCP: O CONFACK [REQsent] id 88 len 14
Jul 2 15:16:14.415: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 2 15:16:14.415: Vi1 LCP: MRU 2048 (0x01040800)
Jul 2 15:16:14.507: Vi1 LCP: TIMEout: State ACKsent
Jul 2 15:16:14.507: Vi1 LCP: O CONFREQ [ACKsent] id 173 len 15
Jul 2 15:16:14.507: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:14.507: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:14.539: Vi1 LCP: I CONFACK [ACKsent] id 173 len 15
Jul 2 15:16:14.539: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 15:16:14.539: Vi1 LCP: MagicNumber 0x121E2132 (0x0506121E2132)
Jul 2 15:16:14.539: Vi1 LCP: State is Open
Jul 2 15:16:14.539: Vi1 PPP: Phase is AUTHENTICATING, by this end [0 sess,
0 load]
Jul 2 15:16:14.539: Vi1 CHAP: O CHALLENGE id 159 len 28 from "nrp1bot"
Jul 2 15:16:14.571: Vi1 CHAP: I RESPONSE id 159 len 34 from "1cardpppoa1_1"
Jul 2 15:16:14.603: Vi1 CHAP: O SUCCESS id 159 len 4
Jul 2 15:16:14.615: Vi1 PPP: Phase is UP [0 sess, 0 load]
Jul 2 15:16:14.615: Vi1 IPCP: O CONFREQ [Not negotiated] id 137 len 10
Jul 2 15:16:14.615: Vi1 IPCP: Address 10.10.20.13 (0x03060A0A140D)
Jul 2 15:16:14.635: Vi1 IPCP: I CONFREQ [REQsent] id 89 len 10
Jul 2 15:16:14.635: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)
Jul 2 15:16:14.635: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 15:16:14.635: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 15:16:14.635: Vi1 IPCP: Pool returned 10.10.20.1
Jul 2 15:16:14.635: Vi1 IPCP: O CONFNAK [REQsent] id 89 len 10
Jul 2 15:16:14.635: Vi1 IPCP: Address 10.10.20.1 (0x03060A0A1401)
Jul 2 15:16:14.647: Vi1 IPCP: I CONFACK [REQsent] id 137 len 10
Jul 2 15:16:14.647: Vi1 IPCP: Address 10.10.20.13 (0x03060A0A140D)
Jul 2 15:16:14.667: Vi1 IPCP: I CONFREQ [ACKrcvd] id 90 len 10
Jul 2 15:16:14.667: Vi1 IPCP: Address 10.10.20.1 (0x03060A0A1401)
Jul 2 15:16:14.667: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.10.20.1, we
want 10.10.20.1
Jul 2 15:16:14.667: Vi1 AAA/AUTHOR/IPCP: Reject 10.10.20.1, using
10.10.20.1
Jul 2 15:16:14.667: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.10.20.1, we
want 10.10.20.1
Jul 2 15:16:14.667: Vi1 IPCP: O CONFACK [ACKrcvd] id 90 len 10
Jul 2 15:16:14.667: Vi1 IPCP: Address 10.10.20.1 (0x03060A0A1401)
Jul 2 15:16:14.667: Vi1 IPCP: State is Open
Jul 2 15:16:14.671: Vi1 IPCP: Install route to 10.10.20.1
Jul 2 15:16:15.603: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access1, changed state to up
Jul 2 15:16:24.056: Vi1 LCP: I ECHOREP [Open] id 1 len 12 magic 0xA60C0000
Jul 2 15:16:24.056: Vi1 LCP: Received id 1, sent id 1, line up
nrp1bot#
nrp1bot#
Jul 2 15:16:29.412: Vi1 LCP: I ECHOREQ [Open] id 91 len 8 magic 0xA60C0000
Jul 2 15:16:29.412: Vi1 LCP: O ECHOREP [Open] id 91 len 8 magic 0x121E2132
nrp1bot#
The remote user initiates a Point-to-Point Protocol over Ethernet (PPPoE) session over the DSL access network. If the remote user cannot initiate a PPPoE session, use the following debug commands in privileged EXEC mode:
Example 3-18 provides a sample of the debug command output that results from these commands.
PPPoE protocol events debugging is on
nrp1bot# debug ppp authentication
PPP authentication debugging is on
nrp1bot# debug ppp negotiation
PPP protocol negotiation debugging is on
nrp1bot# sh debug
PPP:
PPP authentication debugging is on
PPP protocol negotiation debugging is on
VPN:
PPPoE protocol events debugging is on
nrp1bot#
Jul 2 19:07:56.686: PPPoE: IN PADI discovery packet
Jul 2 19:07:56.686: PPPoE: LMAC:ffff.ffff.ffff RMAC:00a0.ccd9.2697 21/33
AT0/0/0.2133
Jul 2 19:07:56.686: PPPoE: PADO OUT from PPPoE tunnel
Jul 2 19:07:56.686: PPPoE: LMAC:0002.b992.7807 RMAC:00a0.ccd9.2697 21/33
AT0/0/0.2133
Jul 2 19:07:56.738: PPPoE: IN PADR discovery packet
Jul 2 19:07:56.738: PPPoE: LMAC:0002.b992.7807 RMAC:00a0.ccd9.2697 21/33
AT0/0/0.2133
Jul 2 19:07:56.738: Vi2 PPP: Phase is DOWN, Setup [0 sess, 0 load]
Jul 2 19:07:56.758: PPPoE: Create session: 1
Jul 2 19:07:56.758: PPPoE: 1: Created
Jul 2 19:07:56.758: PPPoE: LMAC:0002.b992.7807 RMAC:00a0.ccd9.2697 21/33
AT0/0/0.2133
Jul 2 19:07:56.758: PPPoE: PADS OUT from PPPoE tunnel
Jul 2 19:07:56.758: PPPoE: LMAC:0002.b992.7807 RMAC:00a0.ccd9.2697 21/33
AT0/0/0.2133
Jul 2 19:07:56.762: %LINK-3-UPDOWN: Interface Virtual-Access2, changed
state to up
Jul 2 19:07:56.762: Vi2 PPP: Treating connection as a dedicated line
Jul 2 19:07:56.762: Vi2 PPP: Phase is ESTABLISHING, Active Open [0 sess, 0
load]
Jul 2 19:07:56.762: Vi2 LCP: O CONFREQ [Closed] id 1 len 19
Jul 2 19:07:56.762: Vi2 LCP: MRU 1492 (0x010405D4)
Jul 2 19:07:56.762: Vi2 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 19:07:56.762: Vi2 LCP: MagicNumber 0x12F26578 (0x050612F26578)
Jul 2 19:07:56.918: Vi2 LCP: I CONFREQ [REQsent] id 1 len 14
Jul 2 19:07:56.918: Vi2 LCP: MagicNumber 0x001B0B5A (0x0506001B0B5A)
Jul 2 19:07:56.918: Vi2 LCP: PFC (0x0702)
Jul 2 19:07:56.918: Vi2 LCP: ACFC (0x0802)
Jul 2 19:07:56.918: Vi2 LCP: O CONFACK [REQsent] id 1 len 14
Jul 2 19:07:56.918: Vi2 LCP: MagicNumber 0x001B0B5A (0x0506001B0B5A)
Jul 2 19:07:56.918: Vi2 LCP: PFC (0x0702)
Jul 2 19:07:56.918: Vi2 LCP: ACFC (0x0802)
Jul 2 19:07:58.762: Vi2 LCP: TIMEout: State ACKsent
Jul 2 19:07:58.762: Vi2 LCP: O CONFREQ [ACKsent] id 2 len 19
Jul 2 19:07:58.762: Vi2 LCP: MRU 1492 (0x010405D4)
Jul 2 19:07:58.762: Vi2 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 19:07:58.762: Vi2 LCP: MagicNumber 0x12F26578 (0x050612F26578)
Jul 2 19:07:58.798: Vi2 LCP: I CONFACK [ACKsent] id 2 len 19
Jul 2 19:07:58.798: Vi2 LCP: MRU 1492 (0x010405D4)
Jul 2 19:07:58.798: Vi2 LCP: AuthProto CHAP (0x0305C22305)
Jul 2 19:07:58.798: Vi2 LCP: MagicNumber 0x12F26578 (0x050612F26578)
Jul 2 19:07:58.798: Vi2 LCP: State is Open
Jul 2 19:07:58.798: Vi2 PPP: Phase is AUTHENTICATING, by this end [0 sess,
0 load]
Jul 2 19:07:58.798: Vi2 CHAP: O CHALLENGE id 11 len 28 from "nrp1bot"
Jul 2 19:07:58.838: Vi2 CHAP: I RESPONSE id 11 len 34 from "1cardpppoe1_1"
Jul 2 19:07:58.838: Vi2 PPP: Phase is FORWARDING [0 sess, 0 load]
Jul 2 19:07:58.838: Vi2 PPP: Phase is AUTHENTICATING [0 sess, 0 load]
Jul 2 19:07:58.850: Vi2 CHAP: O SUCCESS id 11 len 4
Jul 2 19:07:58.870: Vi2 PPP: Phase is UP [0 sess, 0 load]
Jul 2 19:07:58.870: Vi2 IPCP: O CONFREQ [Closed] id 1 len 10
Jul 2 19:07:58.870: Vi2 IPCP: Address 10.10.21.37 (0x03060A0A1525)
Jul 2 19:07:58.886: Vi2 IPCP: I CONFREQ [REQsent] id 1 len 34
Jul 2 19:07:58.886: Vi2 IPCP: Address 0.0.0.0 (0x030600000000)
Jul 2 19:07:58.886: Vi2 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
Jul 2 19:07:58.886: Vi2 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
Jul 2 19:07:58.886: Vi2 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
Jul 2 19:07:58.890: Vi2 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
Jul 2 19:07:58.890: Vi2 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 19:07:58.890: Vi2 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 19:07:58.890: Vi2 IPCP: Pool returned 10.10.21.26
Jul 2 19:07:58.890: Vi2 IPCP: O CONFREJ [REQsent] id 1 len 28
Jul 2 19:07:58.890: Vi2 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
Jul 2 19:07:58.890: Vi2 IPCP: PrimaryWINS 0.0.0.0 (0x820600000000)
Jul 2 19:07:58.890: Vi2 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)
Jul 2 19:07:58.890: Vi2 IPCP: SecondaryWINS 0.0.0.0 (0x840600000000)
Jul 2 19:07:58.906: Vi2 IPCP: I CONFACK [REQsent] id 1 len 10
Jul 2 19:07:58.906: Vi2 IPCP: Address 10.10.21.37 (0x03060A0A1525)
Jul 2 19:07:58.926: Vi2 IPCP: I CONFREQ [ACKrcvd] id 2 len 10
Jul 2 19:07:58.926: Vi2 IPCP: Address 0.0.0.0 (0x030600000000)
Jul 2 19:07:58.926: Vi2 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
want 10.10.21.26
Jul 2 19:07:58.926: Vi2 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
want 10.10.21.26
Jul 2 19:07:58.926: Vi2 IPCP: O CONFNAK [ACKrcvd] id 2 len 10
Jul 2 19:07:58.926: Vi2 IPCP: Address 10.10.21.26 (0x03060A0A151A)
Jul 2 19:07:58.962: Vi2 IPCP: I CONFREQ [ACKrcvd] id 3 len 10
Jul 2 19:07:58.962: Vi2 IPCP: Address 10.10.21.26 (0x03060A0A151A)
Jul 2 19:07:58.962: Vi2 AAA/AUTHOR/IPCP: Start. Her address 10.10.21.26,
we want 10.10.21.26
Jul 2 19:07:58.966: Vi2 AAA/AUTHOR/IPCP: Reject 10.10.21.26, using
10.10.21.26
Jul 2 19:07:58.966: Vi2 AAA/AUTHOR/IPCP: Done. Her address 10.10.21.26, we
want 10.10.21.26
Jul 2 19:07:58.966: Vi2 IPCP: O CONFACK [ACKrcvd] id 3 len 10
Jul 2 19:07:58.966: Vi2 IPCP: Address 10.10.21.26 (0x03060A0A151A)
Jul 2 19:07:58.966: Vi2 IPCP: State is Open
Jul 2 19:07:58.966: Vi2 IPCP: Install route to 10.10.21.26
Jul 2 19:07:59.850: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access2, changed state to up
The VHG-PE queries RADIUS to associate the remote user with a specific customer MPLS VPN.
Note The VPN's VRF (routing table and other information associated with a specific VPN) must have been pre-instantiated on the VHG/PE. |
If the VHG/PE cannot query the SP RADIUS server, use the following debug commands in privileged EXEC mode:
Example 3-19 provides a sample of the debug command output that results from these commands.
nrp1bot# debug aaa authentication
AAA Authentication debugging is on
nrp1bot# debug aaa authorization
AAA Authorization debugging is on
nrp1bot# debug radius
Radius protocol debugging is on
nrp1bot#
nrp1bot# sh debug
General OS:
AAA Authentication debugging is on
AAA Authorization debugging is on
Radius protocol debugging is on
nrp1bot#
Jul 2 15:47:13.462: AAA: parse name=Virtual-Access1 idb type=21 tty=-1
Jul 2 15:47:13.462: AAA: name=Virtual-Access1 flags=0x11 type=6 shelf=0
slot=0 adapter=0 port=1 channel=0
Jul 2 15:47:13.462: AAA/MEMORY: create_user (0x6167DD48)
user='1cardpppoa1_1' ruser='' port='Virtual-Access1' rem_addr=''
authen_type=CHAP service=PPP priv=1
Jul 2 15:47:13.462: AAA/AUTHEN/START (1344226464): port='Virtual-Access1'
list='' action=LOGIN service=PPP
Jul 2 15:47:13.462: AAA/AUTHEN/START (1344226464): using "default" list
Jul 2 15:47:13.462: AAA/AUTHEN/START (1344226464): Method=radius (radius)
Jul 2 15:47:13.462: RADIUS: ustruct sharecount=1
Jul 2 15:47:13.462: RADIUS: Initial Transmit Virtual-Access1 id 159
172.29.51.235:1645, Access-Request, len 84
Jul 2 15:47:13.462: Attribute 4 6 81010109
Jul 2 15:47:13.462: Attribute 5 6 00000000
Jul 2 15:47:13.462: Attribute 61 6 00000005
Jul 2 15:47:13.462: Attribute 1 15 31636172
Jul 2 15:47:13.462: Attribute 3 19 A0DFA8B1
Jul 2 15:47:13.462: Attribute 6 6 00000002
Jul 2 15:47:13.462: Attribute 7 6 00000001
Jul 2 15:47:13.474: RADIUS: Received from id 159 172.29.51.235:1645,
Access-Accept, len 237
Jul 2 15:47:13.474: Attribute 6 6 00000002
Jul 2 15:47:13.474: Attribute 7 6 00000001
Jul 2 15:47:13.474: Attribute 26 12 00000211F4060000
Jul 2 15:47:13.474: Attribute 26 62 0000000901386C63
Jul 2 15:47:13.474: Attribute 26 51 00000009012D6C63
Jul 2 15:47:13.474: Attribute 26 80 00000009014A6C63
Jul 2 15:47:13.474: AAA/AUTHEN (1344226464): status = PASS
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Authorize LCP
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP (2669002508): Port='Virtual-Access1'
list='' service=NET
Jul 2 15:47:13.474: AAA/AUTHOR/LCP: Vi1 (2669002508) user='1cardpppoa1_1'
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP (2669002508): send AV service=ppp
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP (2669002508): send AV protocol=lcp
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP (2669002508): found list "default"
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP (2669002508): Method=radius (radius)
Jul 2 15:47:13.474: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1"
Jul 2 15:47:13.474: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20"
Jul 2 15:47:13.474: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool"
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR (2669002508): Post authorization status
= PASS_REPL
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Processing AV service=ppp
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Processing AV idletime=1800
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Processing AV interface-config#1 =
ip vrf forwarding 1cardpppoa1
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Processing AV interface-config#2 =
ip unnumbered lo20
Jul 2 15:47:13.474: Vi1 AAA/AUTHOR/LCP: Processing AV interface-config#3 =
peer default ip address pool 1cardpppoa1_1_pool
Jul 2 15:47:13.478: AAA/AUTHOR/LCP: Virtual-Access1: Reconstruct
interface-config= ip vrf forwarding 1cardpppoa1\n ip unnumbered lo20\n peer
default ip address pool 1cardpppoa1_1_pool
Jul 2 15:47:13.478: Vi1 AAA/AUTHOR/LCP: Per-user interface config created:
ppp timeout idle 1800 aaa
ip vrf forwarding 1cardpppoa1\n ip unnumbered lo20\n peer default ip
address pool 1cardpppoa1_1_pool
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM (907722013): Port='Virtual-Access1'
list='' service=NET
Jul 2 15:47:13.490: AAA/AUTHOR/FSM: Vi1 (907722013) user='1cardpppoa1_1'
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM (907722013): send AV service=ppp
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM (907722013): send AV protocol=ip
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM (907722013): found list "default"
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM (907722013): Method=radius (radius)
Jul 2 15:47:13.490: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1" not applied for ip
Jul 2 15:47:13.490: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20" not applied for ip
Jul 2 15:47:13.490: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool" not applied for ip
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR (907722013): Post authorization status =
PASS_REPL
Jul 2 15:47:13.490: Vi1 AAA/AUTHOR/FSM: We can start IPCP
Jul 2 15:47:13.510: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 15:47:13.510: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
Jul 2 15:47:13.510: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
Jul 2 15:47:13.510: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we
want 0.0.0.0
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.10.20.1, we
want 10.10.20.1
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913):
Port='Virtual-Access1' list='' service=NET
Jul 2 15:47:13.542: AAA/AUTHOR/IPCP: Vi1 (1098858913) user='1cardpppoa1_1'
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913): send AV service=ppp
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913): send AV protocol=ip
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913): send AV
addr*10.10.20.1
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913): found list "default"
Jul 2 15:47:13.542: Vi1 AAA/AUTHOR/IPCP (1098858913): Method=radius
(radius)
Jul 2 15:47:13.542: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1" not applied for ip
Jul 2 15:47:13.546: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20" not applied for ip
Jul 2 15:47:13.546: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool" not applied for ip
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR (1098858913): Post authorization status
= PASS_REPL
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR/IPCP: Reject 10.10.20.1, using
10.10.20.1
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR/IPCP: Processing AV addr*10.10.20.1
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
Jul 2 15:47:13.546: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.10.20.1, we
want 10.10.20.1
Jul 2 15:47:14.478: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access1, changed state to up
If the remote user cannot be associated with a specific customer MPLS VPN, use the following debug commands in privileged EXEC mode:
Example 3-20 provides a sample of the debug command output that results from these commands.
nrp1bot# debug radius
Radius protocol debugging is on
nrp1bot# debug vtemplate
Virtual Template debugging is on
nrp1bot#
Jul 2 15:51:47.426: RADIUS: ustruct sharecount=1
Jul 2 15:51:47.426: RADIUS: Initial Transmit Virtual-Access1 id 160
172.29.51.235:1645, Access-Request, len 84
Jul 2 15:51:47.426: Attribute 4 6 81010109
Jul 2 15:51:47.426: Attribute 5 6 00000000
Jul 2 15:51:47.426: Attribute 61 6 00000005
Jul 2 15:51:47.426: Attribute 1 15 31636172
Jul 2 15:51:47.426: Attribute 3 19 A18162B8
Jul 2 15:51:47.426: Attribute 6 6 00000002
Jul 2 15:51:47.426: Attribute 7 6 00000001
Jul 2 15:51:47.434: RADIUS: Received from id 160 172.29.51.235:1645,
Access-Accept, len 237
Jul 2 15:51:47.434: Attribute 6 6 00000002
Jul 2 15:51:47.434: Attribute 7 6 00000001
Jul 2 15:51:47.434: Attribute 26 12 00000211F4060000
Jul 2 15:51:47.434: Attribute 26 62 0000000901386C63
Jul 2 15:51:47.438: Attribute 26 51 00000009012D6C63
Jul 2 15:51:47.438: Attribute 26 80 00000009014A6C63
Jul 2 15:51:47.438: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1"
Jul 2 15:51:47.438: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20"
Jul 2 15:51:47.438: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool"
Jul 2 15:51:47.438: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has
vtemplate/AAA
Jul 2 15:51:47.438: Vi1 VTEMPLATE:
Jul 2 15:51:47.438: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
ppp timeout idle 1800 aaa
ip vrf forwarding 1cardpppoa1
ip unnumbered lo20
peer default ip address pool 1cardpppoa1_1_pool
end
Jul 2 15:51:47.450: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1" not applied for ip
Jul 2 15:51:47.450: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20" not applied for ip
Jul 2 15:51:47.450: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool" not applied for ip
Jul 2 15:51:47.506: RADIUS: cisco AVPair "lcp:interface-config#1 = ip vrf
forwarding 1cardpppoa1" not applied for ip
Jul 2 15:51:47.506: RADIUS: cisco AVPair "lcp:interface-config#2 = ip
unnumbered lo20" not applied for ip
Jul 2 15:51:47.506: RADIUS: cisco AVPair "lcp:interface-config#3 = peer
default ip address pool 1cardpppoa1_1_pool" not applied for ip
Jul 2 15:51:48.438: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access1, changed state to up
nrp1bot#
If the VHG/PE cannot obtain an IP address, use the following debug command in privileged EXEC mode:
Example 3-21 provides a sample of the debug command output that results from this command.
nrp1bot# debug ip peer
IP peer address activity debugging is on
nrp1bot# sh debug
Generic IP:
IP peer address activity debugging is on
nrp1bot#
Jul 2 16:02:20.497: Vi1: Pools to search : 1cardpppoa1_1_pool
Jul 2 16:02:20.497: Vi1: Pool 1cardpppoa1_1_pool returned address =
10.10.20.1
Jul 2 16:02:20.529: Vi1 IPCP: Install route to 10.10.20.1
Jul 2 16:02:21.461: %LINEPROTO-5-UPDOWN: Line protocol on Interface
Virtual-Access1, changed state to up
The following show commands are useful in debugging PPPoX to MPLS VPN integration:
Example 3-22 shows the detailed output that results when you implement these show commands.
nrp1bot# sh atm pvc ppp
VCD / Peak Avg/Min Burst
ATM Int. Name VPI VCI Type VA VASt SC Kbps Kbps Cells VCSt
0/0/0.2033 5 20 33 PVC 1 UP UBR 155000 UP
nrp1bot# sh int virtual-access 2
Virtual-Access2 is up, line protocol is up
Hardware is Virtual Access interface
Interface is unnumbered. Using address of Loopback21 (10.10.21.37)
MTU 1492 bytes, BW 100000 Kbit, DLY 100000 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation PPP, loopback not set
Keepalive set (10 sec)
DTR is pulsed for 5 seconds on reset
Time to interface disconnect: idle 00:29:28
LCP Open
Open: IPCP
Bound to ATM0/0/0.2133 VCD: 6, VPI: 21, VCI: 33
Cloned from virtual-template: 2
Last input 00:00:07, output never, output hang never
Last clearing of "show interface" counters 06:11:22
Queueing strategy: fifo
Output queue 0/40, 0 drops; input queue 0/75, 0 drops
5 minute input rate 0 bits/sec, 0 packets/sec
5 minute output rate 0 bits/sec, 0 packets/sec
157 packets input, 9097 bytes, 0 no buffer
Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
12 packets output, 226 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
0 output buffer failures, 0 output buffers swapped out
0 carrier transitions
nrp1bot# sh ip route vrf 1cardpppoe1
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
10.0.0.0/32 is subnetted, 3 subnets
C 10.10.21.26 is directly connected, Virtual-Access2
C 10.10.21.37 is directly connected, Loopback21
B 10.10.21.38 [200/0] via 10.1.1.4, 07:17:30
nrp1bot# sh ip local pool
Pool Begin End Free In use
1cardpppoa1_1_pool 10.10.20.1 10.10.20.6 6 0
1cardpppoe1_1_pool 10.10.21.26 10.10.21.30 4 1
nrp1bot# sh vpdn session all
%No active L2TP tunnels
%No active L2F tunnels
%No active PPTP tunnels
PPPoE Session Information Total tunnels 1 sessions 1
session id: 1
local MAC address: 0002.b992.7807, remote MAC address: 00a0.ccd9.2697
virtual access interface: Vi2, outgoing interface: AT0/0/0, vc: 21/33
16 packets sent, 161 received
258 bytes sent, 8887 received
nrp1bot#sh vpdn tunnel
%No active L2TP tunnels
%No active L2F tunnels
%No active PPTP tunnels
PPPoE Tunnel Information Total tunnels 1 sessions 1
PPPoE Tunnel Information
Session count: 1
nrp1bot#
This section contains the following troubleshooting topics:
Figure 3-4 shows the topology associated with a VPN-capable service provider's MPLS backbone. In this scenario, you should assume that the customer has outsourced all remote access operations to its service provider.
For reminders on using the command- line interface for viewing debug output, refer to the sections of the Remote Access to MPLS VPN Solution Provisioning Guide 1.0 entitled "User Interface Command Modes" and "User Command Modes." This document can be accessed at the following URL:
http://cco/univercd/cc/td/doc/product/vpn/solution/rampls/index.htm
Table 3-4 (below) corresponds to Figure 3-4, providing a cross-reference to the troubleshooting topics associated with the events that occur when the remote user creates a PPPoX session over DSL in an attempt to access its corporate network or ISP.
Event Shown in Figure 3-4: | Related Troubleshooting Topic(s): |
---|---|
Line1-2: DSL router initiates a PPPoA or PPPoE session. SSG accepts and terminates the PPPoX session. | DSL Router Cannot Initiate PPPoX Session (Step 1 and Step 2) |
Lines 3-4: SSG queries the RADIUS server for attributes of incoming user. SSG completes the remote user's authentication via RADIUS. | SSG Queries the RADIUS Server (Step 3 and Step 4[a]) SSG Completes the Remote User's Authentication (Step 3 and Step 4[b]) |
Line 5: SSG obtains an IP address for the remote user. | |
Lines 6-10: SSG user browses SSD and authenticates. | SSG User Browses SSD and Authenticates (Step 6 through Step 10) |
Line 11: SSG user selects a service from SSD. |
If the DSL router cannot initiate a PPPoX session, use the following debug commands in privileged EXEC mode:
Example 3-23 provides a sample of the debug command output that results from these commands.
nrp1mid# debug ppp negotiation
PPP protocol negotiation debugging is on
nrp1mid# debug ppp authentication
PPP authentication debugging is on
nrp1mid# sh debug
PPP:
PPP authentication debugging is on
PPP protocol negotiation debugging is on
Jul 25 15:02:02.903: Vi1 LCP: I CONFREQ [Listen] id 253 len 14
Jul 25 15:02:02.903: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 25 15:02:02.903: Vi1 LCP: MRU 2048 (0x01040800)
Jul 25 15:02:02.903: Vi1 LCP: O CONFREQ [Listen] id 58 len 15
Jul 25 15:02:02.903: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 25 15:02:02.903: Vi1 LCP: MagicNumber 0x06AA8DAF (0x050606AA8DAF)
Jul 25 15:02:02.903: Vi1 LCP: O CONFACK [Listen] id 253 len 14
Jul 25 15:02:02.903: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 25 15:02:02.903: Vi1 LCP: MRU 2048 (0x01040800)
Jul 25 15:02:02.935: Vi1 LCP: I CONFACK [ACKsent] id 58 len 15
Jul 25 15:02:02.935: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 25 15:02:02.935: Vi1 LCP: MagicNumber 0x06AA8DAF (0x050606AA8DAF)
Jul 25 15:02:02.935: Vi1 LCP: State is Open
Jul 25 15:02:02.935: Vi1 PPP: Phase is AUTHENTICATING, by this end [0 sess, 0 load]
Jul 25 15:02:02.935: Vi1 CHAP: O CHALLENGE id 7 len 28 from "nrp1mid"
Jul 25 15:02:02.967: Vi1 CHAP: I RESPONSE id 7 len 32 from "2cardpppoa1"
Jul 25 15:02:02.967: Vi1 PPP: Phase is FORWARDING [0 sess, 0 load]
Jul 25 15:02:02.967: Vi1 PPP: Phase is AUTHENTICATING [0 sess, 0 load]
Jul 25 15:02:02.979: Vi1 CHAP: O SUCCESS id 7 len 4
Jul 25 15:02:02.979: Vi1 PPP: Phase is UP [0 sess, 0 load]
Jul 25 15:02:02.979: Vi1 IPCP: O CONFREQ [Closed] id 5 len 10
Jul 25 15:02:02.979: Vi1 IPCP: Address 10.1.1.6 (0x030681010106)
Jul 25 15:02:03.015: Vi1 IPCP: I CONFREQ [REQsent] id 254 len 10
Jul 25 15:02:03.015: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)
Jul 25 15:02:03.015: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
Jul 25 15:02:03.015: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.4.1
Jul 25 15:02:03.015: Vi1 IPCP: O CONFNAK [REQsent] id 254 len 10
Jul 25 15:02:03.015: Vi1 IPCP: Address 10.1.4.1 (0x030681010401)
Jul 25 15:02:03.019: Vi1 IPCP: I CONFACK [REQsent] id 5 len 10
Jul 25 15:02:03.019: Vi1 IPCP: Address 10.1.1.6 (0x030681010106)
Jul 25 15:02:03.051: Vi1 IPCP: I CONFREQ [ACKrcvd] id 255 len 10
Jul 25 15:02:03.051: Vi1 IPCP: Address 10.1.4.1 (0x030681010401)
Jul 25 15:02:03.051: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.1.4.1, we want 10.1.4.1
Jul 25 15:02:03.051: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.1.4.1, we want 10.1.4.1
Jul 25 15:02:03.051: Vi1 IPCP: O CONFACK [ACKrcvd] id 255 len 10
Jul 25 15:02:03.051: Vi1 IPCP: Address 10.1.4.1 (0x030681010401)
Jul 25 15:02:03.051: Vi1 IPCP: State is Open
Jul 25 15:02:03.055: Vi1 IPCP: Install route to 10.1.4.1
Jul 25 15:02:03.979: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp1mid#
Note The VPN's VRF (routing table and other information associated with a specific VPN) must have been pre-instantiated on the VHG/PE. |
If SSG cannot query the RADIUS server, use the following debug commands in privileged EXEC mode:
Example 3-24 provides a sample of the debug command output that results from these commands.
nrp1mid# debug aaa authentication
AAA Authentication debugging is on
nrp1mid# debug radius
Radius protocol debugging is on
nrp1mid# debug aaa authorization
AAA Authorization debugging is on
nrp1mid# sh debug
General OS:
AAA Authentication debugging is on
AAA Authorization debugging is on
Radius protocol debugging is on
nrp1mid#
Jul 25 15:37:35.963: AAA: parse name=Virtual-Access1 idb type=21 tty=-1
Jul 25 15:37:35.963: AAA: name=Virtual-Access1 flags=0x11 type=6 shelf=0 slot=0 adapter=0
port=1 channel=0
Jul 25 15:37:35.963: AAA/MEMORY: create_user (0x616AD95C) user='2cardpppoa1' ruser=''
port='Virtual-Access1' rem_addr='' authen_type=CHAP service=PPP priv=1
Jul 25 15:37:35.963: RADIUS: ustruct sharecount=1
Jul 25 15:37:35.963: RADIUS: Initial Transmit Virtual-Access1 id 180 172.29.51.235:1645,
Access-Request, len 82
Jul 25 15:37:35.963: Attribute 4 6 81010106
Jul 25 15:37:35.967: Attribute 5 6 00000001
Jul 25 15:37:35.967: Attribute 61 6 00000005
Jul 25 15:37:35.967: Attribute 1 13 32636172
Jul 25 15:37:35.967: Attribute 3 19 0B6D884F
Jul 25 15:37:35.967: Attribute 6 6 00000002
Jul 25 15:37:35.967: Attribute 7 6 00000001
Jul 25 15:37:35.975: RADIUS: Received from id 180 172.29.51.235:1645, Access-Accept, len
50
Jul 25 15:37:35.975: Attribute 6 6 00000002
Jul 25 15:37:35.975: Attribute 7 6 00000001
Jul 25 15:37:35.975: Attribute 8 6 81010401
Jul 25 15:37:35.975: Attribute 9 6 FFFFFFF8
Jul 25 15:37:35.975: Attribute 12 6 000005DC
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP: Authorize LCP
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP (1705808688): Port='Virtual-Access1' list=''
service=NET
Jul 25 15:37:35.975: AAA/AUTHOR/LCP: Vi1 (1705808688) user='2cardpppoa1'
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP (1705808688): send AV service=ppp
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP (1705808688): send AV protocol=lcp
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP (1705808688): found list "default"
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP (1705808688): Method=radius (radius)
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR (1705808688): Post authorization status = PASS_REPL
Jul 25 15:37:35.975: Vi1 AAA/AUTHOR/LCP: Processing AV service=ppp
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM: (0): Can we start IPCP?
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM (3853248361): Port='Virtual-Access1' list=''
service=NET
Jul 25 15:37:35.979: AAA/AUTHOR/FSM: Vi1 (3853248361) user='2cardpppoa1'
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM (3853248361): send AV service=ppp
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM (3853248361): send AV protocol=ip
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM (3853248361): found list "default"
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM (3853248361): Method=radius (radius)
Jul 25 15:37:35.979: RADIUS: Authorize IP address 10.10.20.1
Jul 25 15:37:35.979: RADIUS: Framed-IP-Netmask 255.255.255.248
Jul 25 15:37:35.979: RADIUS: framed-route 10.1.4.0 255.255.255.248
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR (3853248361): Post authorization status = PASS_REPL
Jul 25 15:37:35.979: Vi1 AAA/AUTHOR/FSM: We can start IPCP
Jul 25 15:37:35.979: RADIUS: ustruct sharecount=3
Jul 25 15:37:35.979: RADIUS: Initial Transmit Virtual-Access1 id 181 172.29.51.235:1646,
Accounting-Request, len 85
Jul 25 15:37:35.979: Attribute 4 6 81010106
Jul 25 15:37:35.979: Attribute 5 6 00000001
Jul 25 15:37:35.979: Attribute 61 6 00000005
Jul 25 15:37:35.979: Attribute 1 13 32636172
Jul 25 15:37:35.979: Attribute 40 6 00000001
Jul 25 15:37:35.979: Attribute 6 6 00000002
Jul 25 15:37:35.979: Attribute 44 10 30303030
Jul 25 15:37:35.979: Attribute 7 6 00000001
Jul 25 15:37:35.979: Attribute 41 6 00000000
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=10.1.4.1
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Processing AV netmask*255.255.255.248
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Processing AV route=10.1.4.0 255.255.255.248
Jul 25 15:37:36.015: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
Jul 25 15:37:36.019: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 10.1.4.1
Jul 25 15:37:36.027: RADIUS: Received from id 181 172.29.51.235:1646, Accounting-response,
len 20
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.1.4.1, we want 10.1.4.1
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Processing AV service=ppp
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Processing AV addr=10.1.4.1
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Processing AV netmask*255.255.255.248
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Processing AV route=10.1.4.0 255.255.255.248
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
Jul 25 15:37:36.055: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.1.4.1, we want 10.1.4.1
Jul 25 15:37:36.059: AAA: parse name=Virtual-Access1 idb type=21 tty=-1
Jul 25 15:37:36.059: AAA: name=Virtual-Access1 flags=0x11 type=6 shelf=0 slot=0 adapter=0
port=1 channel=0
Jul 25 15:37:36.059: AAA/MEMORY: create_user (0x6165132C) user='2cardpppoa1' ruser=''
port='' rem_addr='' authen_type=CHAP service=PPP priv=1
Jul 25 15:37:36.059: RADIUS: ustruct sharecount=1
Jul 25 15:37:36.063: RADIUS: Initial Transmit id 182 172.29.51.235:1646,
Accounting-Request, len 91
Jul 25 15:37:36.063: Attribute 4 6 81010106
Jul 25 15:37:36.063: Attribute 5 6 00000001
Jul 25 15:37:36.063: Attribute 61 6 00000005
Jul 25 15:37:36.063: Attribute 1 13 32636172
Jul 25 15:37:36.063: Attribute 40 6 00000001
Jul 25 15:37:36.063: Attribute 6 6 00000002
Jul 25 15:37:36.063: Attribute 44 10 30303030
Jul 25 15:37:36.063: Attribute 7 6 00000001
Jul 25 15:37:36.063: Attribute 8 6 81010401
Jul 25 15:37:36.063: Attribute 41 6 00000000
Jul 25 15:37:36.119: RADIUS: Received from id 182 172.29.51.235:1646, Accounting-response,
len 20
Jul 25 15:37:36.119: SSG: free_user (0x6165132C) user='2cardpppoa1' ruser=''
port='1633984376' rem_addr='' authen_type=CHAP service=PPP priv=1
radius_servertype='0x0000' account_info='0x611BA7BC'
Jul 25 15:37:36.119: AAA/MEMORY: free_user (0x6165132C) user='2cardpppoa1' ruser=''
port='' rem_addr='' authen_type=CHAP service=PPP priv=1
Jul 25 15:37:36.975: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp1mid#
If SSG cannot complete the authentication, use the following debug commands in privileged EXEC mode:
Example 3-25 provides a sample of the debug command output that results from these commands.
nrp1mid# debug radius
Radius protocol debugging is on
nrp1mid# debug vtemp
nrp1mid# debug vtemplate
Virtual Template debugging is on
nrp1mid#
nrp1mid# sh debug
VTEMPLATE:
Virtual Template debugging is on
Radius protocol debugging is on
nrp1mid#
Jul 25 15:04:21.970: RADIUS: ustruct sharecount=1
Jul 25 15:04:21.970: RADIUS: Initial Transmit Virtual-Access1 id 149 172.29.51.235:1645,
Access-Request, len 82
Jul 25 15:04:21.970: Attribute 4 6 81010106
Jul 25 15:04:21.970: Attribute 5 6 00000001
Jul 25 15:04:21.970: Attribute 61 6 00000005
Jul 25 15:04:21.970: Attribute 1 13 32636172
Jul 25 15:04:21.970: Attribute 3 19 08D5DC82
Jul 25 15:04:21.970: Attribute 6 6 00000002
Jul 25 15:04:21.970: Attribute 7 6 00000001
Jul 25 15:04:21.982: RADIUS: Received from id 149 172.29.51.235:1645, Access-Accept, len
50
Jul 25 15:04:21.982: Attribute 6 6 00000002
Jul 25 15:04:21.982: Attribute 7 6 00000001
Jul 25 15:04:21.982: Attribute 8 6 81010401
Jul 25 15:04:21.982: Attribute 9 6 FFFFFFF8
Jul 25 15:04:21.982: Attribute 12 6 000005DC
Jul 25 15:04:21.982: RADIUS: Authorize IP address 10.10.20.1
Jul 25 15:04:21.982: RADIUS: Framed-IP-Netmask 255.255.255.248
Jul 25 15:04:21.982: RADIUS: framed-route 10.1.4.0 255.255.255.248
Jul 25 15:04:21.982: RADIUS: ustruct sharecount=3
Jul 25 15:04:21.982: RADIUS: Initial Transmit Virtual-Access1 id 150 172.29.51.235:1646,
Accounting-Request, len 85
Jul 25 15:04:21.982: Attribute 4 6 81010106
Jul 25 15:04:21.982: Attribute 5 6 00000001
Jul 25 15:04:21.982: Attribute 61 6 00000005
Jul 25 15:04:21.986: Attribute 1 13 32636172
Jul 25 15:04:21.986: Attribute 40 6 00000001
Jul 25 15:04:21.986: Attribute 6 6 00000002
Jul 25 15:04:21.986: Attribute 44 10 30303030
Jul 25 15:04:21.986: Attribute 7 6 00000001
Jul 25 15:04:21.986: Attribute 41 6 00000000
Jul 25 15:04:22.050: RADIUS: ustruct sharecount=1
Jul 25 15:04:22.054: RADIUS: Initial Transmit id 151 172.29.51.235:1646,
Accounting-Request, len 91
Jul 25 15:04:22.054: Attribute 4 6 81010106
Jul 25 15:04:22.054: Attribute 5 6 00000001
Jul 25 15:04:22.054: Attribute 61 6 00000005
Jul 25 15:04:22.054: Attribute 1 13 32636172
Jul 25 15:04:22.054: Attribute 40 6 00000001
Jul 25 15:04:22.054: Attribute 6 6 00000002
Jul 25 15:04:22.054: Attribute 44 10 30303030
Jul 25 15:04:22.054: Attribute 7 6 00000001
Jul 25 15:04:22.054: Attribute 8 6 81010401
Jul 25 15:04:22.054: Attribute 41 6 00000000
Jul 25 15:04:22.070: RADIUS: Received from id 150 172.29.51.235:1646, Accounting-response,
len 20
Jul 25 15:04:22.154: RADIUS: Received from id 151 172.29.51.235:1646, Accounting-response,
len 20
Jul 25 15:04:22.982: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp1mid#
If SSG cannot obtain an IP address, use the following debug command in privileged EXEC mode:
Example 3-26 provides a sample of the debug command output that results from this command.
nrp1mid# debug ip peer
IP peer address activity debugging is on
nrp1mid#
nrp1mid# sh debug
Generic IP:
IP peer address activity debugging is onnrp1mid#
nrp1mid#
Jul 25 15:07:22.032: set_ip_peer_addr: Vi1: address = 10.10.20.1 (4)
Jul 25 15:07:22.072: set_ip_peer_addr: Vi1: address = 10.10.20.1 (4)
Jul 25 15:07:22.076: Vi1 IPCP: Install route to 10.1.4.1
Jul 25 15:07:22.992: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
If the SSG user cannot browse SSD and authenticate, use the following debug commands in privileged EXEC mode:
Example 3-27 provides a sample of the debug command output that results from the debug ssg events and debug ssg ctrl-events commands. Example 3-28 provides a sample of the debug command output that results from the debug radius command.
nrp1mid# debug ssg events
SSG events debugging is on
nrp1mid# debug ssg ctrl-events
SSG control path events debugging is on
nrp1mid# sh debug
SSG:
SSG control path events debugging is on
SSG events debugging is on
nrp1mid#
Jul 25 15:12:48.002: SSG-CTL-EVN: Received cmd (1,ssg_user1) from 10.1.4.2.
Jul 25 15:12:48.002: SSG-CTL-EVN: Add cmd=1 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:12:48.002: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:12:48.002: SSG-CTL-EVN: Handling account logon for host 10.1.4.2.
Jul 25 15:12:48.002: SSG-CTL-EVN: Authenticating user ssg_user1.
Jul 25 15:12:48.026: SSG-CTL-EVN: Creating HostObject for host 10.1.4.2.
Jul 25 15:12:48.026: SSG-EVN: HostObject::HostObject: size = 288
Jul 25 15:12:48.026: SSG-EVN: HostObject::Reset
Jul 25 15:12:48.026: SSG-CTL-EVN: Set Host Mac Address .
Jul 25 15:12:48.026: SSG-CTL-EVN: ** attr->type = 6
Jul 25 15:12:48.026: SSG-CTL-EVN: ATTR_LOOP = 1
Jul 25 15:12:48.026: SSG-CTL-EVN: HostObject::InsertServiceList MP3
Jul 25 15:12:48.026: SSG-CTL-EVN: ATTR_LOOP = 2
Jul 25 15:12:48.030: SSG-CTL-EVN: HostObject::InsertServiceList Warez
Jul 25 15:12:48.030: SSG-CTL-EVN: ATTR_LOOP = 3
Jul 25 15:12:48.030: SSG-CTL-EVN: Account logon is accepted (10.1.4.2,ssg_user1).
Jul 25 15:12:48.030: SSG-CTL-EVN: Send cmd 1 to host 10.1.4.2. dst=172.29.51.236:34966
Jul 25 15:12:48.030: SSG-CTL-EVN: Activating HostObject for host 10.1.4.2.
Jul 25 15:12:48.550: SSG-CTL-EVN: Received cmd (4, ) from 10.1.4.2.
Jul 25 15:12:48.550: SSG-CTL-EVN: Add cmd=4 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:12:48.550: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:12:48.550: SSG-CTL-EVN: Handling account status query for host 10.1.4.2.
Jul 25 15:12:48.550: SSG-CTL-EVN: Collecting the account info and ack the query.
Jul 25 15:12:48.550: SSG-CTL-EVN: Send cmd 4 to host 10.1.4.2. dst=172.29.51.236:34965
Jul 25 15:12:53.494: SSG-CTL-EVN: Received cmd (4, ) from 10.1.4.2.
Jul 25 15:12:53.494: SSG-CTL-EVN: Add cmd=4 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:12:53.494: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:12:53.494: SSG-CTL-EVN: Handling account status query for host 10.1.4.2.
Jul 25 15:12:53.494: SSG-CTL-EVN: Collecting the account info and ack the query.
Jul 25 15:12:53.494: SSG-CTL-EVN: Send cmd 4 to host 10.1.4.2. dst=172.29.51.236:34966
Jul 25 15:12:58.503: SSG-EVN: - SSGTimeout Process: Collect 2 Host IPs for Timeout check.
nrp1mid# debug radius
Radius protocol debugging is on
nrp1mid# sh debug
Radius protocol debugging is on
nrp1mid#
[1st request when the ssg user is logging in to retrieve the service's menu]
Jul 25 15:18:58.944: RADIUS: ustruct sharecount=1
Jul 25 15:18:58.944: RADIUS: Initial Transmit id 168 172.29.51.235:1645, Access-Request,
len 61
Jul 25 15:18:58.944: Attribute 4 6 81010106
Jul 25 15:18:58.944: Attribute 61 6 00000000
Jul 25 15:18:58.944: Attribute 1 11 7373675F
Jul 25 15:18:58.944: Attribute 2 18 8F1A945D
Jul 25 15:18:58.952: RADIUS: Received from id 168 172.29.51.235:1645, Access-Accept, len
52
Jul 25 15:18:58.952: Attribute 6 6 0000000A
Jul 25 15:18:58.952: Attribute 26 12 00000009FA064E4D
Jul 25 15:18:58.952: Attribute 26 14 00000009FA084E57
Jul 25 15:18:58.952: RADIUS: saved authorization data for user 611BA988 at 61776FEC
Jul 25 15:18:58.956: RADIUS: ustruct sharecount=1
Jul 25 15:18:58.956: RADIUS: Initial Transmit id 169 172.29.51.235:1646, Accounting-Re
quest, len 89
Jul 25 15:18:58.956: Attribute 4 6 81010106
Jul 25 15:18:58.956: Attribute 5 6 00000000
Jul 25 15:18:58.956: Attribute 61 6 00000005
Jul 25 15:18:58.956: Attribute 1 11 7373675F
Jul 25 15:18:58.956: Attribute 40 6 00000001
Jul 25 15:18:58.956: Attribute 6 6 00000002
Jul 25 15:18:58.956: Attribute 44 10 30303030
Jul 25 15:18:58.956: Attribute 7 6 00000001
Jul 25 15:18:58.956: Attribute 8 6 81010402
Jul 25 15:18:58.956: Attribute 41 6 00000000
Jul 25 15:18:59.032: RADIUS: Received from id 169 172.29.51.235:1646, Accounting-respon
se, len 20
nrp1mid#
nrp1mid#
nrp1mid#
After authenticating, the user receives an updated web page with the services they are authorized to access. Once the user selects a service, SSD initiates a request to the SSG with the user name, password, and service name. SSG queries the service provider (SP) radius server and receives the service profile. For "proxy" service types, the SSG queries the Cust RADIUS server to authenticate the remote user. SSG can optionally assign an address to the remote user.
If the SSG user cannot select a service from SSD, use the following debug commands in privileged EXEC mode:
Example 3-29 provides a sample of the debug command output that results from the debug ssg events and debug ssg ctrl-events commands. Example 3-30 provides a sample of the output that results from the debug radius command.
Jul 25 15:12:59.867: SSG-CTL-EVN: Received cmd (11,MP3) from 10.1.4.2.
Jul 25 15:12:59.867: SSG-CTL-EVN: Add cmd=11 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:12:59.867: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:12:59.867: SSG-CTL-EVN: Handling service logon for host 10.1.4.2.
Jul 25 15:12:59.867: SSG-CTL-EVN: Locating the HostObject for host 10.1.4.2.
Jul 25 15:12:59.867: SSG-CTL-EVN: Checking maximum service count.
Jul 25 15:12:59.867: SSG-CTL-EVN: Downloading service profile for service MP3.
Jul 25 15:12:59.867: SSG-EVN: DownloadProfile: getting profile for MP3 from AAA
Jul 25 15:12:59.879: SSG-CTL-EVN: Creating ServiceInfo for service MP3.
Jul 25 15:12:59.879: SSG-EVN: - ServiceInfo object already exists
Jul 25 15:12:59.879: SSG-EVN: ServiceInfo::Reset
Jul 25 15:12:59.879: SSG-EVN: DstNet::~DstNet
Jul 25 15:12:59.879: SSG-EVN: DstNet::~DstNet: deleting m_pInclude
Jul 25 15:12:59.879: SSG-EVN: NetSegmentList::~NetSegmentList
Jul 25 15:12:59.879: SSG-EVN: DstNet::DstNet: size = 12
Jul 25 15:12:59.879: SSG-EVN: NetSegmentList::NetSegmentList: size = 4
Jul 25 15:12:59.879: SSG-CTL-EVN: Checking service mode.
Jul 25 15:12:59.879: SSG-CTL-EVN: ServiceLogon: Enqueue request of service MP3
Jul 25 15:12:59.879: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:12:59.879: SSG-CTL-EVN: Handling service logon for host 10.1.4.2.
Jul 25 15:12:59.879: SSG-CTL-EVN: Locating the HostObject for host 10.1.4.2.
Jul 25 15:12:59.879: SSG-CTL-EVN: Creating ConnectionObject (10.1.4.2, MP3).
Jul 25 15:12:59.879: SSG-EVN: ConnectionObject::ConnectionObject: size = 112
Jul 25 15:12:59.879: SSG-EVN: Opening connection for user ssg_user1
Jul 25 15:12:59.879: SSG-CTL-EVN: Service logon is accepted.
Jul 25 15:12:59.879: SSG-CTL-EVN: Send cmd 11 to host 10.1.4.2. dst=172.29.51.236:34965
Jul 25 15:12:59.879: SSG-CTL-EVN: Activating the ConnectionObject.
Jul 25 15:12:59.879: SSG-CTL-EVN: Acct Start: local: user_name=ssg_user1
Jul 25 15:12:59.879: SSG-CTL-EVN: GetConnClass NULL len 0
Jul 25 15:12:59.879: SSG-CTL-EVN: Get Host Mac Address 0000.0000.0000
Jul 25 15:12:59.879: SSG-CTL-EVN: SSG: Accounting:: AddCiscoVSA
Jul 25 15:12:59.879: SSG-CTL-EVN: SSG: Accounting:: AddCiscoVSA add serviceName=MP3
Jul 25 15:12:59.883: SSG-CTL-EVN: AddCiscoVSA: add serviceUserName=ssg_user1
Jul 25 15:12:59.883: SSG-CTL-EVN: AddCiscoVSA: no adding V attr pService 611BBE78
Jul 25 15:13:00.335: SSG-CTL-EVN: Received cmd (4, ) from 10.1.4.2.
Jul 25 15:13:00.335: SSG-CTL-EVN: Add cmd=4 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:13:00.335: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:13:00.335: SSG-CTL-EVN: Handling account status query for host 10.1.4.2.
Jul 25 15:13:00.335: SSG-CTL-EVN: Collecting the account info and ack the query.
Jul 25 15:13:00.335: SSG-CTL-EVN: Send cmd 4 to host 10.1.4.2. dst=172.29.51.236:34966
Jul 25 15:13:00.383: SSG-CTL-EVN: Received cmd (4,MP3) from 10.1.4.2.
Jul 25 15:13:00.383: SSG-CTL-EVN: Add cmd=4 from 10.1.4.2 into SSG control cmd queue.
Jul 25 15:13:00.383: SSG-CTL-EVN: Dequeue a cmd from the cmd queue and pass it to cmd
handler.
Jul 25 15:13:00.383: SSG-CTL-EVN: Handling account status query for host 10.1.4.2.
Jul 25 15:13:00.383: SSG-CTL-EVN: Collecting the account info and ack the query.
Jul 25 15:13:00.383: SSG-CTL-EVN: Send cmd 4 to host 10.1.4.2. dst=172.29.51.236:34965
nrp1mid#
[2nd request when user has selected the MP3 service. A radius request is sent to obtain
the attributes of that service profile]
nrp1mid#
Jul 25 15:19:29.062: RADIUS: ustruct sharecount=1
Jul 25 15:19:29.062: RADIUS: Initial Transmit id 170 172.29.51.235:1645, Access-Reques
t, len 61
Jul 25 15:19:29.062: Attribute 4 6 81010106
Jul 25 15:19:29.062: Attribute 61 6 00000000
Jul 25 15:19:29.066: Attribute 1 5 4D503302
Jul 25 15:19:29.066: Attribute 2 18 31D0AD9B
Jul 25 15:19:29.066: Attribute 6 6 00000005
Jul 25 15:19:29.070: RADIUS: Received from id 170 172.29.51.235:1645, Access-Accept, le
n 95
Jul 25 15:19:29.074: Attribute 6 6 00000005
Jul 25 15:19:29.074: Attribute 26 19 00000009FB0D494D
Jul 25 15:19:29.074: Attribute 26 30 00000009FB185231
Jul 25 15:19:29.074: Attribute 26 10 00000009FB044D43
Jul 25 15:19:29.074: Attribute 26 10 00000009FB045450
Jul 25 15:19:29.074: RADIUS: saved authorization data for user 611BA988 at 61776FEC
Jul 25 15:19:29.074: RADIUS: ustruct sharecount=1
Jul 25 15:19:29.074: RADIUS: Initial Transmit id 171 172.29.51.235:1646, Accounting-Re
quest, len 89
Jul 25 15:19:29.074: Attribute 4 6 81010106
Jul 25 15:19:29.074: Attribute 5 6 00000000
Jul 25 15:19:29.074: Attribute 61 6 00000005
Jul 25 15:19:29.074: Attribute 1 11 7373675F
Jul 25 15:19:29.074: Attribute 40 6 00000001
Jul 25 15:19:29.074: Attribute 6 6 00000002
Jul 25 15:19:29.074: Attribute 44 10 30303030
Jul 25 15:19:29.074: Attribute 7 6 00000001
Jul 25 15:19:29.074: Attribute 8 6 81010402
Jul 25 15:19:29.074: Attribute 41 6 00000000
Jul 25 15:19:29.162: RADIUS: Received from id 171 172.29.51.235:1646, Accounting-response,
len 20
nrp1mid#
nrp1mid#
The following show commands are useful in debugging PPPoX Remote Access SSG to MPLS VPN integration:
Example 3-31 shows the detailed output that results when you implement these show commands.
nrp1mid# sh atm pvc ppp
VCD / Peak Avg/Min Burst
ATM Int. Name VPI VCI Type VA VASt SC Kbps Kbps Cells VCSt
0/0/0.3033 3 30 33 PVC 1 UP UBR 155000 UP
nrp1mid# sh int virtual-access 1
Virtual-Access1 is up, line protocol is up
Hardware is Virtual Access interface
Interface is unnumbered. Using address of Loopback0 (10.1.1.6)
MTU 1500 bytes, BW 100000 Kbit, DLY 100000 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation PPP, loopback not set
Keepalive set (10 sec)
DTR is pulsed for 5 seconds on reset
LCP Open
Open: IPCP
Bound to ATM0/0/0.3033 VCD: 3, VPI: 30, VCI: 33
Cloned from virtual-template: 1
Last input 00:00:00, output never, output hang never
Last clearing of "show interface" counters 18:41:07
Queueing strategy: fifo
Output queue 0/40, 0 drops; input queue 0/75, 0 drops
5 minute input rate 1000 bits/sec, 3 packets/sec
5 minute output rate 0 bits/sec, 0 packets/sec
45630 packets input, 2288960 bytes, 0 no buffer
Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
20723 packets output, 815083 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
0 output buffer failures, 0 output buffers swapped out
0 carrier transitions
nrp1bot# sh vpdn session all
%No active L2TP tunnels
%No active L2F tunnels
%No active PPTP tunnels
PPPoE Session Information Total tunnels 1 sessions 1
session id: 1
local MAC address: 0002.b992.7807, remote MAC address: 00a0.ccd9.2697
virtual access interface: Vi2, outgoing interface: AT0/0/0, vc: 21/33
16 packets sent, 161 received
258 bytes sent, 8887 received
nrp1bot# sh vpdn tunnel
%No active L2TP tunnels
%No active L2F tunnels
%No active PPTP tunnels
PPPoE Tunnel Information Total tunnels 1 sessions 1
PPPoE Tunnel Information
Session count: 1
nrp1bot#
nrp1mid# sh ssg host
1: 10.1.4.1
2: 10.1.4.2
nrp1mid# sh ssg host 10.1.4.2
------------------------ HostObject Content -----------------------
Activated: TRUE
Interface:
User Name: ssg_user1
Host IP: 10.1.4.2
Msg IP: 172.29.51.236 (9902)
Host DNS IP: 0.0.0.0
Maximum Session Timeout: 0 seconds
Host Idle Timeout: 0 seconds
Class Attr: NONE
User logged on since: 16:13:46.000 UTC Wed Jul 25 2001
User last activity at: 16:13:51.000 UTC Wed Jul 25 2001
Default Service: NONE
DNS Default Service: NONE
Active Services: NONE
AutoService: NONE
Subscribed Services: MP3; Warez;
nrp1mid# sh ssg bindi
Warez -> ATM0/0/0.201
MP3 -> ATM0/0/0.200
nrp1mid# sh ssg connection 10.1.4.2 MP3
------------------------ ConnectionObject Content -----------------------
User Name: ssg_user1
Owner Host: 10.1.4.2
Associated Service: MP3
Connection State: 0 (UP)
Connection Started since:
15:19:29.000 UTC Wed Jul 25 2001
User last activity at: 15:23:29.000 UTC Wed Jul 25 2001
Connection Traffic Statistics:
Input Bytes = 9680 (HI = 0), Input packets = 242
Output Bytes = 9680 (HI = 0), Output packets = 242
nrp1mid# sh ssg service MP3
------------------------ ServiceInfo Content -----------------------
Uplink IDB: ATM0/0/0.200
Name: MP3
Type: PASS-THROUGH
Mode: CONCURRENT
Service Session Timeout: 0 seconds
Service Idle Timeout: 0 seconds
Authentication Type: CHAP
DNS Server(s):
Included Network Segments:
10.21.0.0/255.255.0.0
Excluded Network Segments:
ConnectionCount 1
Full User Name not used
Domain List:
Active Connections:
1 : RealIP=0.0.0.0, Subscriber=10.1.4.2
This section contains the following troubleshooting topics:
Figure 3-5 shows the overall topology of an integrated DSL to MPLS VPN solution, within the context of a VPN-capable service provider's MPLS backbone. In this scenario, the customer has outsourced all remote access operations to its service provider. In addition, but not explicitly shown in Figure 3-5, the service provider operates an MPLS VPN that interconnects all customer sites. An incoming PPPoX session (which arrives at the NAS 64000 NRP) is L2TP-tunneled to the VHG/PE 6400 NRP, which maps the session to the corresponding VRF.
Note DSL L2TP to MPLS VPN integration is very similar to the dial-in L2TP to MPLS VPN solution discussed in the "Troubleshooting Dial Access to MPLS VPN Integration" section on page 2-1. |
For reminders on using the command line interface for viewing debug command output, refer to the sections of the Remote Access to MPLS VPN Solution Provisioning Guide 1.0 entitled "User Interface Command Modes" and "User Command Modes." This document can be accessed at the following URL:
http://cco/univercd/cc/td/doc/product/vpn/solution/rampls/index.htm
Table 3-5 (below) corresponds to Figure 3-5, providing a cross-reference to the troubleshooting topics associated with DSL L2TP to MPLS VPN integration.
Event Shown in Figure 3-5: | Related Troubleshooting Topics: |
---|---|
Line 1: User initiates a PPPoE session or the DSL router initiates a PPPoA session. |
|
Line 2: NAS accepts the PPPoX session. | |
Line 3: NAS partially authenticates the user with CHAP or PAP and obtains tunnel information. | |
Line 4: NAS initiates a tunnel to the VHG-PE/LNS (if L2TP tunnel does not exist). | |
Lines 5-10: PPP session is created and connection is extended to terminate on the VHG-PE/LNS; NAS propagates available PPP information. | Create Tunnel Session and Propagate PPP Information (Step 5 through Step 10[a]) |
Lines 5-10: VHG-PE/LNS completes the authentication, associates the remote user with a specific customer MPLS VPN, and obtains an IP address. |
If NAS does not accept the PPPoX session, use the following debug commands in privileged EXEC mode:
Example 3-32 provides a sample of the debug command output that results from these commands.
[LAC Only]
nrp1mid# debug ppp negotiation
PPP protocol negotiation debugging is on
nrp1mid# debug ppp authentication
PPP authentication debugging is on
nrp1mid# sh debug
PPP:
PPP authentication debugging is on
PPP protocol negotiation debugging is on
Jul 26 17:49:19.120: Vi1 LCP: I CONFREQ [Listen] id 114 len 14
Jul 26 17:49:19.120: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 26 17:49:19.120: Vi1 LCP: MRU 2048 (0x01040800)
Jul 26 17:49:19.120: Vi1 LCP: O CONFREQ [Listen] id 175 len 15
Jul 26 17:49:19.120: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 26 17:49:19.120: Vi1 LCP: MagicNumber 0x07BEC6D3 (0x050607BEC6D3)
Jul 26 17:49:19.120: Vi1 LCP: O CONFACK [Listen] id 114 len 14
Jul 26 17:49:19.120: Vi1 LCP: MagicNumber 0xA60C0000 (0x0506A60C0000)
Jul 26 17:49:19.120: Vi1 LCP: MRU 2048 (0x01040800)
Jul 26 17:49:19.156: Vi1 LCP: I CONFACK [ACKsent] id 175 len 15
Jul 26 17:49:19.156: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 26 17:49:19.156: Vi1 LCP: MagicNumber 0x07BEC6D3 (0x050607BEC6D3)
Jul 26 17:49:19.156: Vi1 LCP: State is Open
Jul 26 17:49:19.156: Vi1 PPP: Phase is AUTHENTICATING, by this end [0 sess, 0 load]
Jul 26 17:49:19.156: Vi1 CHAP: O CHALLENGE id 27 len 28 from "nrp1mid"
Jul 26 17:49:19.192: Vi1 CHAP: I RESPONSE id 27 len 39 from "anchan@gcoe.com"
Jul 26 17:49:19.192: Vi1 PPP: Phase is FORWARDING [0 sess, 0 load]
Jul 26 17:49:20.208: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
If NAS does not authenticate or obtain tunnel information, use the following debug commands in privileged EXEC mode:
Example 3-33 provides a sample of the debug command output that results from these commands.
nrp1mid# debug vpdn event
VPDN events debugging is on
nrp1mid# sh debug
VPN:
VPDN events debugging is on
nrp1mid#
Jul 26 17:59:14.202: VPDN: Domain based tunnel lookup. Domain is gcoe.com
Jul 26 17:59:14.202: Vi1 VPDN: Looking for tunnel -- gcoe.com --
Jul 26 17:59:14.230: Vi1 VPDN/RPMS/: Got tunnel info for gcoe.com
[LAC Only]
nrp1mid# debug aaa author
AAA Authorization debugging is on
nrp1mid# debug aaa authentication
AAA Authentication debugging is on
nrp1mid# debug radius
Radius protocol debugging is on
nrp1mid# sh debug
General OS:
AAA Authentication debugging is on
AAA Authorization debugging is on
Radius protocol debugging is on
nrp1mid#
Jul 26 17:55:17.204: AAA: parse name=Virtual-Access1 idb type=21 tty=-1
Jul 26 17:55:17.204: AAA: name=Virtual-Access1 flags=0x11 type=6 shelf=0 slot=0 adapter=0
port=1 channel=0
Jul 26 17:55:17.204: AAA/MEMORY: create_user (0x61622070) user='gcoe.com' ruser=''
port='Virtual-Access1' rem_addr='' authen_type=NONE service=LOGIN priv=0
Jul 26 17:55:17.204: Virtual-Access1 AAA/AUTHOR/VPDN (3484971203): Port='Virtual-Access1'
list='default' service=NET
Jul 26 17:55:17.204: AAA/AUTHOR/VPDN: Virtual-Access1 (3484971203) user='gcoe.com'
Jul 26 17:55:17.204: Virtual-Access1 AAA/AUTHOR/VPDN (3484971203): send AV service=ppp
Jul 26 17:55:17.204: Virtual-Access1 AAA/AUTHOR/VPDN (3484971203): send AV protocol=vpdn
Jul 26 17:55:17.204: Virtual-Access1 AAA/AUTHOR/VPDN (3484971203): found list "default"
Jul 26 17:55:17.204: Virtual-Access1 AAA/AUTHOR/VPDN (3484971203): Method=radius (radius)
Jul 26 17:55:17.204: RADIUS: authenticating to get author data
Jul 26 17:55:17.204: RADIUS: ustruct sharecount=2
Jul 26 17:55:17.204: RADIUS: Initial Transmit Virtual-Access1 id 215 172.29.51.235:1645,
Access-Request, len 75
Jul 26 17:55:17.204: Attribute 4 6 81010106
Jul 26 17:55:17.204: Attribute 5 6 00000001
Jul 26 17:55:17.204: Attribute 61 6 00000005
Jul 26 17:55:17.204: Attribute 1 13 72656462
Jul 26 17:55:17.204: Attribute 2 18 C0859715
Jul 26 17:55:17.204: Attribute 6 6 00000005
Jul 26 17:55:17.216: RADIUS: Received from id 215 172.29.51.235:1645, Access-Accept, len
87
Jul 26 17:55:17.216: Attribute 6 6 00000005
Jul 26 17:55:17.216: Attribute 64 6 01000003
Jul 26 17:55:17.216: Attribute 66 12 01313239
Jul 26 17:55:17.216: Attribute 67 12 01313239
Jul 26 17:55:17.216: Attribute 69 21 013BEAC4
Jul 26 17:55:17.216: Attribute 90 10 016E7270
Jul 26 17:55:17.216: RADIUS: saved authorization data for user 61622070 at 6167E678
Jul 26 17:55:17.216: RADIUS: Tunnel-Type, [01] 00 00 03
Jul 26 17:55:17.216: RADIUS: TAS(1) created and enqueued.
Jul 26 17:55:17.216: RADIUS: Tunnel-Client-Endpoint, [01] 10.1.1.6
Jul 26 17:55:17.216: RADIUS: Tunnel-Server-Endpoint, [01] 10.1.1.7
Jul 26 17:55:17.216: RADIUS: Tunnel-Password decrypted, [01] bodega
Jul 26 17:55:17.216: RADIUS: Tunnel-Cli-Auth, [01] nrp1mid
Jul 26 17:55:17.216: RADIUS: TAS(1) takes precedence over tagged attributes,
tunnel_type=l2tp
Jul 26 17:55:17.216: RADIUS: Tunnel-Medium-Type not set. Use default type 'IP'.
Jul 26 17:55:17.216: RADIUS: Tunnel-Medium-Type not set. Use default type 'IP'.
Jul 26 17:55:17.216: RADIUS: free TAS(1)
Jul 26 17:55:17.216: AAA/AUTHOR (3484971203): Post authorization status = PASS_REPL
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV tunnel-type*l2tp
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV ip-addresses=10.1.1.7
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV source-ip=10.1.1.6
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV tunnel-id=nrp1mid
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV l2tp-tunnel-password=bodega
Jul 26 17:55:17.216: AAA/AUTHOR/VPDN: Processing AV tunnel-tag*1
Jul 26 17:55:17.216: AAA/MEMORY: free_user (0x61622070) user='gcoe.com' ruser=''
port='Virtual-Access1' rem_addr='' authen_type=NONE service=LOGIN priv=0
Jul 26 17:55:17.220: AAA: parse name=Virtual-Access1 idb type=21 tty=-1
Jul 26 17:55:17.220: AAA: name=Virtual-Access1 flags=0x11 type=6 shelf=0 slot=0 adapter=0
port=1 channel=0
Jul 26 17:55:17.224: AAA/MEMORY: create_user (0x61622070) user='anchan@gcoe.com' ruser=''
port='Virtual-Access1' rem_addr='' authen_type=CHAP service=PPP priv=1
Jul 26 17:55:17.224: RADIUS: ustruct sharecount=3
Jul 26 17:55:17.224: RADIUS: Initial Transmit Virtual-Access1 id 216 172.29.51.235:1646,
Accounting-Request, len 159
Jul 26 17:55:17.228: Attribute 4 6 81010106
Jul 26 17:55:17.228: Attribute 5 6 00000001
Jul 26 17:55:17.228: Attribute 61 6 00000005
Jul 26 17:55:17.228: Attribute 1 20 616E6368
Jul 26 17:55:17.228: Attribute 40 6 00000001
Jul 26 17:55:17.228: Attribute 45 6 00000002
Jul 26 17:55:17.228: Attribute 6 6 00000002
Jul 26 17:55:17.228: Attribute 44 10 30303030
Jul 26 17:55:17.228: Attribute 7 6 00000001
Jul 26 17:55:17.228: Attribute 67 13 01313239
Jul 26 17:55:17.228: Attribute 66 13 01313239
Jul 26 17:55:17.228: Attribute 90 11 016E7270
Jul 26 17:55:17.228: Attribute 91 11 016E7270
Jul 26 17:55:17.228: Attribute 68 13 32303937
Jul 26 17:55:17.228: Attribute 41 6 00000000
Jul 26 17:55:17.268: RADIUS: Received from id 216 172.29.51.235:1646, Accounting-response,
len 20
Jul 26 17:55:18.224: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp1mid#
If the NAS cannot establish a tunnel, use the following debug commands in privileged EXEC mode:
Example 3-34 provides a sample of the debug command output that results from these commands.
[LAC Only]
nrp1mid# debug vpdn event
VPDN events debugging is on
nrp1mid# debug vpdn l2x-events
L2X protocol events debugging is on
nrp1mid# sh debug
VPN:
L2X protocol events debugging is on
VPDN events debugging is on
nrp1mid#
nrp1mid#
nrp1mid#
Jul 26 18:04:15.198: VPDN: Domain based tunnel lookup. Domain is gcoe.com
Jul 26 18:04:15.198: Vi1 VPDN: Looking for tunnel -- gcoe.com --
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: Got tunnel info for gcoe.com
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: LAC nrp1mid
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: source-ip 10.1.1.6
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: l2tp-busy-disconnect yes
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: l2tp-tunnel-password xxxxxx
Jul 26 18:04:15.222: Vi1 VPDN/RPMS/: IP 10.1.1.7
Jul 26 18:04:15.222: Vi1 VPDN/: curlvl 1 Address 0: 10.1.1.7, priority 1
Jul 26 18:04:15.222: Vi1 VPDN/: Select non-active address 10.1.1.7, priority 1
Jul 26 18:04:15.222: Tnl 41197 L2TP: SM State idle
Jul 26 18:04:15.222: Tnl 41197 L2TP: O SCCRQ
Jul 26 18:04:15.226: Tnl 41197 L2TP: Tunnel state change from idle to wait-ctl-reply
Jul 26 18:04:15.226: Tnl 41197 L2TP: SM State wait-ctl-reply
Jul 26 18:04:15.226: Vi1 VPDN: Find LNS process created
Jul 26 18:04:15.226: Vi1 VPDN: Forward to address 10.1.1.7
Jul 26 18:04:15.226: Vi1 VPDN: Pending
Jul 26 18:04:15.226: Vi1 VPDN: Process created
Jul 26 18:04:15.226: Tnl 41197 L2TP: I SCCRP from nrp1mid
Jul 26 18:04:15.226: Tnl 41197 L2TP: Got a challenge from remote peer, nrp1mid
Jul 26 18:04:15.226: Tnl 41197 L2TP: Got a response from remote peer, nrp1mid
Jul 26 18:04:15.226: Tnl 41197 L2TP: Tunnel Authentication success
Jul 26 18:04:15.226: Tnl 41197 L2TP: Tunnel state change from wait-ctl-reply to
established
Jul 26 18:04:15.226: Tnl 41197 L2TP: O SCCCN to nrp1mid tnlid 29847
Jul 26 18:04:15.230: Tnl 41197 L2TP: SM State established
Jul 26 18:04:15.230: Vi1 VPDN: Forwarding...
Jul 26 18:04:15.230: Vi1 VPDN: Bind interface direction=1
Jul 26 18:04:15.230: Tnl/Cl 41197/28 L2TP: Session FS enabled
Jul 26 18:04:15.230: Tnl/Cl 41197/28 L2TP: Session state change from idle to
wait-for-tunnel
Jul 26 18:04:15.230: Vi1 Tnl/Cl 41197/28 L2TP: Create session
Jul 26 18:04:15.230: Tnl 41197 L2TP: SM State established
Jul 26 18:04:15.230: Vi1 Tnl/Cl 41197/28 L2TP: O ICRQ to nrp1mid 29847/0
Jul 26 18:04:15.230: Vi1 Tnl/Cl 41197/28 L2TP: Session state change from wait-for-tunnel
to wait-reply
Jul 26 18:04:15.230: Vi1 VPDN: anchan@gcoe.com is forwarded
Jul 26 18:04:15.234: Vi1 Tnl/Cl 41197/28 L2TP: O ICCN to nrp1mid 29847/28
Jul 26 18:04:15.234: Vi1 Tnl/Cl 41197/28 L2TP: Session state change from wait-reply to
established
Jul 26 18:04:16.230: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp1mid#
[LNS Only]
nrp2mid# debug vpdn event
VPDN events debugging is on
nrp2mid# debug vpdn l2x-events
L2X protocol events debugging is on
nrp2mid# sh debug
VPN:
L2X protocol events debugging is on
VPDN events debugging is on
nrp2mid#
Jul 26 18:04:15.226: L2TP: I SCCRQ from nrp1mid tnl 41197
Jul 26 18:04:15.226: Tnl 29847 L2TP: Got a challenge in SCCRQ, nrp1mid
Jul 26 18:04:15.226: Tnl 29847 L2TP: New tunnel created for remote nrp1mid, address
10.1.1.6
Jul 26 18:04:15.226: Tnl 29847 L2TP: O SCCRP to nrp1mid tnlid 41197
Jul 26 18:04:15.226: Tnl 29847 L2TP: Tunnel state change from idle to wait-ctl-reply
Jul 26 18:04:15.230: Tnl 29847 L2TP: I SCCCN from nrp1mid tnl 41197
Jul 26 18:04:15.230: Tnl 29847 L2TP: Got a Challenge Response in SCCCN from nrp1mid
Jul 26 18:04:15.230: Tnl 29847 L2TP: Tunnel Authentication success
Jul 26 18:04:15.230: Tnl 29847 L2TP: Tunnel state change from wait-ctl-reply to
established
Jul 26 18:04:15.230: Tnl 29847 L2TP: SM State established
Jul 26 18:04:15.230: Tnl 29847 L2TP: I ICRQ from nrp1mid tnl 41197
Jul 26 18:04:15.230: Tnl/Cl 29847/28 L2TP: Session FS enabled
Jul 26 18:04:15.230: Tnl/Cl 29847/28 L2TP: Session state change from idle to wait-connect
Jul 26 18:04:15.234: Tnl/Cl 29847/28 L2TP: New session created
Jul 26 18:04:15.234: Tnl/Cl 29847/28 L2TP: O ICRP to nrp1mid 41197/28
Jul 26 18:04:15.234: Tnl/Cl 29847/28 L2TP: I ICCN from nrp1mid tnl 41197, cl 28
Jul 26 18:04:15.234: Tnl/Cl 29847/28 L2TP: Session state change from wait-connect to
established
Jul 26 18:04:15.234: Vi1 VPDN: Virtual interface created for anchan@gcoe.com
Jul 26 18:04:15.234: Vi1 VPDN: Clone from Vtemplate 1 filterPPP=0 blocking
Jul 26 18:04:15.258: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
Jul 26 18:04:15.258: Vi1 VPDN: Bind interface direction=2
Jul 26 18:04:15.258: Vi1 VPDN: PPP LCP accepted rcv CONFACK
Jul 26 18:04:15.258: Vi1 VPDN: PPP LCP accepted sent CONFACK
Jul 26 18:04:16.270: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp2mid#
If the NAS and the VHG/PE cannot authenticate each other, use the following debug commands in privileged EXEC mode:
Example 3-35 provides a sample of the debug command output that results from these commands.
[LNS Only]
nrp2mid# debug ppp authentication
PPP authentication debugging is on
nrp2mid# debug ppp negotiation
PPP protocol negotiation debugging is on
nrp2mid# sh debug
PPP:
PPP authentication debugging is on
PPP protocol negotiation debugging is on
nrp2mid#
Jul 26 18:10:34.197: Vi1 PPP: Phase is DOWN, Setup [0 sess, 0 load]
Jul 26 18:10:34.221: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
Jul 26 18:10:34.221: Vi1 PPP: Using set call direction
Jul 26 18:10:34.221: Vi1 PPP: Treating connection as a callin
Jul 26 18:10:34.221: Vi1 PPP: Phase is ESTABLISHING, Passive Open [0 sess, 0 load]
Jul 26 18:10:34.221: Vi1 PPP: No remote authentication for call-in
Jul 26 18:10:34.221: Vi1 LCP: State is Listen
Jul 26 18:10:34.221: Vi1 LCP: I FORCED CONFREQ len 11
Jul 26 18:10:34.221: Vi1 LCP: AuthProto CHAP (0x0305C22305)
Jul 26 18:10:34.221: Vi1 LCP: MagicNumber 0x07D22332 (0x050607D22332)
Jul 26 18:10:34.221: Vi1 PPP: Phase is AUTHENTICATING, by this end [0 sess, 0 load]
Jul 26 18:10:34.221: Vi1 CHAP: O CHALLENGE id 31 len 28 from "nrp2mid"
Jul 26 18:10:34.221: Vi1 CHAP: I RESPONSE id 31 len 39 from "anchan@gcoe.com"
Jul 26 18:10:34.233: Vi1 CHAP: O SUCCESS id 31 len 4
Jul 26 18:10:34.249: Vi1 PPP: Phase is UP [0 sess, 0 load]
Jul 26 18:10:34.249: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10
Jul 26 18:10:34.249: Vi1 IPCP: Address 10.60.1.1 (0x03060A3C0101)
Jul 26 18:10:34.289: Vi1 IPCP: I CONFREQ [REQsent] id 210 len 10
Jul 26 18:10:34.289: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)
Jul 26 18:10:34.289: Vi1 AAA/AUTHOR/IPCP: Start. Her address 0.0.0.0, we want 0.0.0.0
Jul 26 18:10:34.289: Vi1 AAA/AUTHOR/IPCP: Done. Her address 0.0.0.0, we want 0.0.0.0
Jul 26 18:10:34.289: Vi1 IPCP: Pool returned 10.60.1.2
Jul 26 18:10:34.289: Vi1 IPCP: O CONFNAK [REQsent] id 210 len 10
Jul 26 18:10:34.289: Vi1 IPCP: Address 10.60.1.2 (0x03060A3C0102)
Jul 26 18:10:34.293: Vi1 IPCP: I CONFACK [REQsent] id 1 len 10
Jul 26 18:10:34.293: Vi1 IPCP: Address 10.60.1.1 (0x03060A3C0101)
Jul 26 18:10:34.329: Vi1 IPCP: I CONFREQ [ACKrcvd] id 211 len 10
Jul 26 18:10:34.329: Vi1 IPCP: Address 10.60.1.2 (0x03060A3C0102)
Jul 26 18:10:34.329: Vi1 AAA/AUTHOR/IPCP: Start. Her address 10.60.1.2, we want 10.60.1.2
Jul 26 18:10:34.329: Vi1 AAA/AUTHOR/IPCP: Reject 10.60.1.2, using 10.60.1.2
Jul 26 18:10:34.329: Vi1 AAA/AUTHOR/IPCP: Done. Her address 10.60.1.2, we want 10.60.1.2
Jul 26 18:10:34.329: Vi1 IPCP: O CONFACK [ACKrcvd] id 211 len 10
Jul 26 18:10:34.329: Vi1 IPCP: Address 10.60.1.2 (0x03060A3C0102)
Jul 26 18:10:34.329: Vi1 IPCP: State is Open
Jul 26 18:10:34.333: Vi1 IPCP: Install route to 10.60.1.2
Jul 26 18:10:35.241: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
Jul 26 18:10:36.221: Vi1 LCP: TIMEout: State Open
Jul 26 18:10:44.113: Vi1 LCP: I ECHOREQ [Open] id 212 len 8 magic 0xA60C0000
Jul 26 18:10:44.113: Vi1 LCP: O ECHOREP [Open] id 212 len 8 magic 0x07D22332
Jul 26 18:10:54.110: Vi1 LCP: I ECHOREQ [Open] id 213 len 8 magic 0xA60C0000
Jul 26 18:10:54.110: Vi1 LCP: O ECHOREP [Open] id 213 len 8 magic 0x07D22332
Jul 26 18:10:54.194: Vi1 LCP: I ECHOREP [Open] id 1 len 12 magic 0xA60C0000
Jul 26 18:10:54.194: Vi1 LCP: Received id 1, sent id 1, line up
nrp2mid#
If the tunnel is not created and the remaining PPP information is not propagated, use the following debug commands in privileged EXEC mode:
Example 3-36 provides a sample of the debug command output that results from these commands.
[LNS Only]
nrp2mid# debug aaa per-user
AAA Per-user attributes debugging is on
nrp2mid# debug vtemplate
Virtual Template debugging is on
nrp2mid# debug ip peer
IP peer address activity debugging is on
nrp2mid# sh debug
General OS:
AAA Per-user attributes debugging is on
Generic IP:
IP peer address activity debugging is on
VTEMPLATE:
Virtual Template debugging is on
nrp2mid#
Jul 26 18:13:39.212: Vt1 VTEMPLATE: Unable to create and clone vaccess
Jul 26 18:13:39.212: Vi1 VTEMPLATE: Reuse Vi1, recycle queue size 0
Jul 26 18:13:39.212: Vi1 VTEMPLATE: Hardware address 0002.b992.7793
Jul 26 18:13:39.212: Vi1 VTEMPLATE: Has a new cloneblk vtemplate, now it has vtemplate
Jul 26 18:13:39.212: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
Jul 26 18:13:39.212: Vi1 VTEMPLATE: Clone from Virtual-Template1
interface Virtual-Access1
default ip address
no ip address
encap ppp
no ip address
ip mroute-cache
end
Jul 26 18:13:39.236: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state to up
Jul 26 18:13:39.248: Vi1 VTEMPLATE: Has a new cloneblk AAA, now it has vtemplate/AAA
Jul 26 18:13:39.248: Vi1 VTEMPLATE: ************* CLONE VACCESS1 *****************
Jul 26 18:13:39.248: Vi1 VTEMPLATE: Clone from AAA
interface Virtual-Access1
ip vrf forwarding vpndsl
ip unnumbered loopback100
peer default ip address pool vpndslpool
end
Jul 26 18:13:39.304: Vi1: Pools to search : vpndslpool
Jul 26 18:13:39.304: Vi1: Pool vpndslpool returned address = 10.60.1.2
Jul 26 18:13:39.344: Vi1 AAA/AUTHOR/PER-USER: Event IP_UP
Jul 26 18:13:39.344: Vi1 AAA/AUTHOR: IP_UP
Jul 26 18:13:39.344: Vi1 AAA/PER-USER: processing author params.
Jul 26 18:13:39.344: Vi1 IPCP: Install route to 10.60.1.2
Jul 26 18:13:40.244: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1,
changed state to up
nrp2mid#
This section provides the following examples of how you can show information for the events outlined in:
The information provided here applies only to DSL access to MPLS VPN integration. For more information about the configuration and troubleshooting tasks associated with L2TP, please refer to the Cisco Configuring Virtual Private Networks document at the following URL:
http://www.cisco.com/univercd/cc/td/doc/product/software/ios121/121cgcr/dialns_c/dnsprt3/dcdvpn.htm
To verify the details of L2TP tunnel setup and session on the NAS, use the following show commands:
Example 3-37 provides a sample of the debug command output that results from these commands.
[LAC Only]
nrp1mid# sh vpdn
L2TP Tunnel and Session Information Total tunnels 1 sessions 1
LocID RemID Remote Name State Remote Address Port Sessions
48083 43245 nrp1mid est 10.1.1.1 1701 1
LocID RemID TunID Intf Username State Last Chg Fastswitch
30 30 48083 Vi1 anchan@gcoe est 00:00:46 enabled
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
[LNS Only]
nrp2mid# sh vpdn
L2TP Tunnel and Session Information Total tunnels 1 sessions 1
LocID RemID Remote Name State Remote Address Port Sessions
43245 48083 nrp1mid est 10.1.1.6 1701 1
LocID RemID TunID Intf Username State Last Chg Fastswitch
30 30 43245 Vi1 anchan@gcoe est 00:00:50 enabled
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp1mid# sh vpdn tunnel
L2TP Tunnel Information Total tunnels 1 sessions 1
LocID RemID Remote Name State Remote Address Port Sessions
48083 43245 nrp1mid est 10.1.1.7 1701 1
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp1mid# sh vpdn tunnel all
L2TP Tunnel Information Total tunnels 1 sessions 1
Tunnel id 48083 is up, remote id is 43245, 1 active sessions
Tunnel state is established, time since change 00:03:44
Remote tunnel name is nrp1mid
Internet Address 10.1.1.7, port 1701
Local tunnel name is nrp1mid
Internet Address 10.1.1.6, port 1701
53 packets sent, 47 received
4222 bytes sent, 1026 received
Control Ns 4, Nr 2
Local RWS 4500 (default), Remote RWS 4500 (max)
Retransmission time 1, max 1 seconds
Unsent queuesize 0, max 0
Resend queuesize 0, max 2
Total resends 0, ZLB ACKs sent 0
Current nosession queue check 0 of 5
Retransmit time distribution: 0 0 0 0 0 0 0 0 0
Sessions disconnected due to lack of resources 0
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp1mid#
nrp1mid# sh vpdn session
L2TP Session Information Total tunnels 1 sessions 1
LocID RemID TunID Intf Username State Last Chg Fastswitch
30 30 48083 Vi1 anchan@gcoe est 00:04:39 enabled
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp1mid# sh user
Line User Host(s) Idle Location
* 2 vty 0 idle 00:00:00 10.21.65.35
Vi1 anchan@gcoe Virtual PPP (ATM ) 00:06:34
Interface User Mode Idle Peer Address
nrp1mid# sh caller
Active Idle
Line User Service Time Time
vty 0 - VTY 00:35:25 00:00:00
Vi1 anchan@gcoe.com PPP ATM 00:07:38 00:07:39
nrp1mid# sh caller user anchan@gcoe.com
User: anchan@gcoe.com, line Vi1, service PPP ATM
Active time 00:07:48, Idle time 00:07:49
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, CHAP (<- none)
IP: Local 10.1.1.6
VPDN: NAS nrp1mid, MID 30, MID Unknown
HGW , NAS CLID 0, HGW CLID 0, tunnel open
Counts: 23313 packets input, 914960 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
17392 packets output, 214903 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
nrp1mid#
nrp1mid# sh vpdn history failure
Table size: 20
Number of entries in table: 1
User: anchan@gcoe.com, MID = 29
NAS: nrp1mid, IP address = 10.1.1.6, CLID = 0
Gateway: Information is not applicable
Log time: 23:47:32, Error repeat count: 26
Failure type: The remote server closed this session
Failure reason: Result 2, Error 6, Disconnect from PPP
To verify the details of the L2TP tunnel setup, PPP sessions, virtual access interface configurations, and local address pool assignment on the VHG-PE/LNS, use the following show commands:
Example 3-38 shows the detailed output that would result from these show commands.
nrp2mid# sh vpdn tunnel
L2TP Tunnel Information Total tunnels 1 sessions 1
LocID RemID Remote Name State Remote Address Port Sessions
43245 48083 nrp1mid est 10.1.1.6 1701 1
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp2mid#
nrp2mid# sh vpdn tunnel all
L2TP Tunnel Information Total tunnels 1 sessions 1
Tunnel id 43245 is up, remote id is 48083, 1 active sessions
Tunnel state is established, time since change 00:03:49
Remote tunnel name is nrp1mid
Internet Address 10.1.1.6, port 1701
Local tunnel name is nrp1mid
Internet Address 10.1.2.26, port 1701
49 packets sent, 56 received
1070 bytes sent, 2386 received
Control Ns 2, Nr 4
Local RWS 4500 (default), Remote RWS 4500 (max)
Retransmission time 1, max 1 seconds
Unsent queuesize 0, max 0
Resend queuesize 0, max 1
Total resends 0, ZLB ACKs sent 2
Current nosession queue check 0 of 5
Retransmit time distribution: 0 0 0 0 0 0 0 0 0
Sessions disconnected due to lack of resources 0
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp2mid#
nrp2mid# sh vpdn session
L2TP Session Information Total tunnels 1 sessions 1
LocID RemID TunID Intf Username State Last Chg Fastswitch
30 30 43245 Vi1 anchan@gcoe est 00:04:45 enabled
%No active L2F tunnels
%No active PPTP tunnels
%No active PPPoE tunnels
nrp2mid#
nrp2mid# sh user
Line User Host(s) Idle Location
* 2 vty 0 idle 00:00:00 10.21.65.35
3 vty 1 idle 23:47:18 ssd
Vi1 anchan@gcoe Virtual PPP (L2TP ) 00:00:01
Interface User Mode Idle Peer Address
nrp1mid# sh caller
Active Idle
Line User Service Time Time
vty 0 - VTY 00:35:25 00:00:00
Vi1 anchan@gcoe.com PPP ATM 00:07:38 00:07:39
nrp2mid# sh caller user anchan@gcoe.com
User: anchan@gcoe.com, line Vi1, service PPP L2TP
Active time 00:08:04, Idle time 00:00:00
Timeouts: Absolute Idle
Limits: - -
Disconnect in: - -
PPP: LCP Open, CHAP (<- AAA), IPCP
IP: Local 10.60.1.1, remote 10.60.1.2
VPDN: NAS nrp1mid, MID 30, MID Unknown
HGW nrp1mid, NAS CLID 0, HGW CLID 0, tunnel open
Counts: 117 packets input, 3752 bytes, 0 no buffer
0 input errors, 0 CRC, 0 frame, 0 overrun
103 packets output, 1446 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
nrp2mid# sh vpdn history failure
Table size: 20
Number of entries in table: 1
User: anchan@gcoe.com, MID = 22
NAS: nrp1mid, IP address = 10.1.1.6, CLID = 0
Gateway: nrp1mid, IP address = 10.1.2.26, CLID = 0
Log time: 22:49:53, Error repeat count: 18
Failure type: The remote server closed this session
Failure reason: Result 2, Error 6, Disconnect from PPP
nrp2mid# sh int virtual-access 1
Virtual-Access1 is up, line protocol is up
Hardware is Virtual Access interface
Interface is unnumbered. Using address of Loopback100 (10.60.1.1)
MTU 1500 bytes, BW 100000 Kbit, DLY 100000 usec,
reliability 255/255, txload 1/255, rxload 1/255
Encapsulation PPP, loopback not set
Keepalive set (10 sec)
DTR is pulsed for 5 seconds on reset
LCP Open
Open: IPCP
Last input 00:00:02, output never, output hang never
Last clearing of "show interface" counters 01:42:43
Queueing strategy: fifo
Output queue 0/40, 0 drops; input queue 0/75, 0 drops
5 minute input rate 0 bits/sec, 0 packets/sec
5 minute output rate 0 bits/sec, 0 packets/sec
1399 packets input, 48172 bytes, 0 no buffer
Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
1231 packets output, 17238 bytes, 0 underruns
0 output errors, 0 collisions, 0 interface resets
0 output buffer failures, 0 output buffers swapped out
0 carrier transitions
nrp2mid# sh int virtual-access 1 configuration
Virtual-Access1 is an L2TP link interface
Building configuration...
interface Virtual-Access1 configuration...
ip vrf forwarding vpndsl
ip unnumbered Loopback100
ip mtu 1460
ip mroute-cache
nrp2mid# sh ip route vrf vpndsl
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
10.0.0.0/32 is subnetted, 2 subnets
C 10.60.1.2 is directly connected, Virtual-Access1
C 10.60.1.1 is directly connected, Loopback100
nrp2mid#
nrp2mid# sh ip local pool
Pool Begin End Free In use
vpn-nrp 6.0.0.1 6.0.0.254 254 0
vpndslpool 10.60.1.2 10.60.1.5 3 1
The features described here may be used with various dsl access methods. This section describes how to troubleshoot the feature itself. For information on troubleshooting the main call flow for the specific access method, see the access method sections.
This section includes:
Troubleshooting the Framed-Route VRF Aware Feature
Verifying and Troubleshooting On-demand Address Pools
On the VHG/PE, verify that the subnet sent to the CPE is in the appropriate VRF routing table:
show ip route vrf <vrf name>
If the subnet is not in the correct VRF routing table, troubleshoot the RADIUS exchange between the VHG/PE and the RADIUS AR server, checking to make sure the AV pair containing the subnet is being exchanged. Use the following commands:
debug aaa authorization
debug aaa authentication
debug aaa per-user
debug radius
debug ip routing vrf vrf name to which PPP session belongs
c72d9-1#
*Sep 4 09:42:33.627: AAA/AUTHOR (0x55): Pick method list 'default'
*Sep 4 09:42:33.631: AAA/AUTHEN/PPP (00000055): Pick method list 'default'
*Sep 4 09:42:33.631: RADIUS: Pick NAS IP for uid=85 tableid=0 cfg_addr=10.10.104.9
best_addr=0.0.0.0
*Sep 4 09:42:33.631: RADIUS/ENCODE(00000055): acct_session_id: 146
*Sep 4 09:42:33.631: RADIUS(00000055): sending
*Sep 4 09:42:33.631: RADIUS(00000055): Send to unknown id 21647/157 10.10.100.3:1645,
Access-Request, len 103
*Sep 4 09:42:33.635: RADIUS: authenticator 96 9E 2F 52 E4 9E 98 10 - E5 B1 B4 77 F5 F4
40 63
*Sep 4 09:42:33.635: RADIUS: Framed-Protocol [7] 6 PPP [1]
*Sep 4 09:42:33.635: RADIUS: User-Name [1] 24 "U0001N1P3V1.9@V1.9.com"
*Sep 4 09:42:33.635: RADIUS: CHAP-Password [3] 19 *
*Sep 4 09:42:33.635: RADIUS: NAS-Port-Type [61] 6 ISDN [2]
*Sep 4 09:42:33.635: RADIUS: Called-Station-Id [30] 6 "9111"
*Sep 4 09:42:33.635: RADIUS: Service-Type [6] 6 Framed [2]
*Sep 4 09:42:33.635: RADIUS: NAS-IP-Address [4] 6 10.10.104.9
*Sep 4 09:42:33.635: RADIUS: Acct-Session-Id [44] 10 "00000092"
*Sep 4 09:42:33.639: RADIUS: Received from id 21647/157 10.10.100.3:1645, Access-Accept,
len 478
*Sep 4 09:42:33.639: RADIUS: authenticator AA 76 9F 6E 15 06 14 5D - 4B DA F0 6C E6 25
D3 C4
*Sep 4 09:42:33.639: RADIUS: Service-Type [6] 6 Framed [2]
*Sep 4 09:42:33.639: RADIUS: Framed-Protocol [7] 6 PPP [1]
*Sep 4 09:42:33.639: RADIUS: Vendor, Cisco [26] 83
*Sep 4 09:42:33.639: RADIUS: Cisco AVpair [1] 77 "lcp:interface-config=ip vrf
forwarding V1.9.com \n ip unnumbered loopback 9"
*Sep 4 09:42:33.639: RADIUS: Vendor, Cisco [26] 75
*Sep 4 09:42:33.639: RADIUS: Cisco AVpair [1] 69 "ip:route=vrf V1.9.com
192.168.200.0 255.255.255.0 32.1.9.10 tag 250"
*Sep 4 09:42:33.639: RADIUS(00000055): Received from id 21647/157
*Sep 4 09:42:33.643: ppp118 PPP/AAA: Check Attr: service-type
*Sep 4 09:42:33.643: ppp118 PPP/AAA: Check Attr: Framed-Protocol
*Sep 4 09:42:33.643: ppp118 PPP/AAA: Check Attr: interface-config:Peruser I/F
*Sep 4 09:42:33.643: ppp118 PPP/AAA: Check Attr: route:Peruser
*Sep 4 09:42:33.663: %LINK-3-UPDOWN: Interface Virtual-Access10, changed state to up
*Sep 4 09:42:33.663: AAA/AUTHEN/PPP (00000055): Pick method list 'default'
*Sep 4 09:42:33.663: Vi10 AAA/AUTHOR/LCP: Process Author
*Sep 4 09:42:33.663: Vi10 AAA/AUTHOR/LCP: Process Attr: interface-config
*Sep 4 09:42:33.663: AAA/AUTHOR: Processing PerUser AV interface-config
*Sep 4 09:42:33.663: Vi10 AAA/AUTHOR/LCP: Process Attr: interface-config
*Sep 4 09:42:33.663: Vi10 AAA/AUTHOR/LCP: IF_config:
ip vrf forwarding V1.9.com \n ip unnumbered loopback 9
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: FSM authorization not needed
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/FSM: We can start IPCP
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: Start. Her address 32.1.9.10, we want 0.0.0.0
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: Reject 32.1.9.10, using 0.0.0.0
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: Processing AV route
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: Authorization succeeded
*Sep 4 09:42:33.719: Vi10 AAA/AUTHOR/IPCP: Done. Her address 32.1.9.10, we want 0.0.0.0
*Sep 4 09:42:33.727: AAA/AUTHOR: Processing PerUser AV route
*Sep 4 09:42:33.727: Vi10 AAA/PERUSER/ROUTE: route string: IP route vrf V1.9.com
192.168.200.0 255.255.255.0 32.1.9.10 tag 250
*Sep 4 09:42:33.735: RT(V1.9.com): closer admin distance for 32.1.9.10, flushing 1 routes
*Sep 4 09:42:33.735: RT(V1.9.com): NET-RED 32.1.9.10/32
*Sep 4 09:42:33.735: RT(V1.9.com): NET-RED queued, Queue size 1
*Sep 4 09:42:33.735: RT(V1.9.com): add 32.1.9.10/32 via 0.0.0.0, connected metric [0/0]
*Sep 4 09:42:33.735: RT(V1.9.com): NET-RED 32.1.9.10/32
*Sep 4 09:42:33.735: RT(V1.9.com): NET-RED push
*Sep 4 09:42:33.735: RT(V1.9.com): NET-RED queued, Queue size 2
*Sep 4 09:42:33.747: AAA/PER-USER: command = [IP route vrf V1.9.com 192.168.200.0
255.255.255.0 32.1.9.10 tag 250
]
*Sep 4 09:42:33.747: AAA/PER-USER: line = [IP route vrf V1.9.com 192.168.200.0
255.255.255.0 32.1.9.10 tag 250]
*Sep 4 09:42:33.751: RT(V1.9.com): add 192.168.200.0/24 via 32.1.9.10, static metric
[1/0]
*Sep 4 09:42:33.751: RT(V1.9.com): NET-RED 192.168.200.0/24
*Sep 4 09:42:33.751: RT(V1.9.com): NET-RED queued, Queue size 1
*Sep 4 09:42:33.763: is_up: 1 state: 4 sub state: 1 line: 0 has_route: True
*Sep 4 09:42:34.663: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access10,
changed state to up
When you disconnect, you will see the static route being removed:
*Sep 4 09:56:43.713: %LINK-3-UPDOWN: Interface Virtual-Access10, changed state to down
*Sep 4 09:56:43.713: is_up: 0 state: 0 sub state: 1 line: 0 has_route: True
*Sep 4 09:56:43.713: RT(V1.9.com): interface Virtual-Access10 removed from routing table
*Sep 4 09:56:43.713: RT(V1.9.com): Pruning routes for Virtual-Access10 (1)
*Sep 4 09:56:43.713: RT(V1.9.com): delete route to 32.1.9.10 via 0.0.0.0,
Virtual-Access10
*Sep 4 09:56:43.713: RT(V1.9.com): no routes to 32.1.9.10, flushing
*Sep 4 09:56:43.713: RT(V1.9.com): NET-RED 32.1.9.10/32
*Sep 4 09:56:43.713: RT(V1.9.com): NET-RED queued, Queue size 1
*Sep 4 09:56:43.713: RT(V1.9.com): add 32.1.9.10/32 via 0.0.0.0, static metric [1/0]
*Sep 4 09:56:43.713: RT(V1.9.com): NET-RED 32.1.9.10/32
*Sep 4 09:56:43.713: RT(V1.9.com): NET-RED queued, Queue size 2
*Sep 4 09:56:44.713: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access10,
changed state to down
c72d9-1#
c72d9-1#
*Sep 4 09:57:03.712: AAA/PER-USER: command = [no IP route vrf V1.9.com 192.168.200.0
255.255.255.0 32.1.9.10 tag 250]
*Sep 4 09:57:03.712: AAA/PER-USER: line = [no IP route vrf V1.9.com 192.168.200.0
255.255.255.0 32.1.9.10 tag 250]
*Sep 4 09:57:03.724: AAA/AUTHOR: decrement ref cnt for ip route 192.168.200.0
255.255.255.0 32.1.9.10 to 0
*Sep 4 09:57:03.724: RT(V1.9.com): del 192.168.200.0 via 32.1.9.10, static metric [1/0]
*Sep 4 09:57:03.724: RT(V1.9.com): delete network route to 192.168.200.0
*Sep 4 09:57:03.724: RT(V1.9.com): NET-RED 192.168.200.0/24
*Sep 4 09:57:03.724: RT(V1.9.com): NET-RED queued, Queue size 1
Show ip route output:
c72d9-1#sh ip rout vrf V1.9.com conn
32.0.0.0/32 is subnetted, 2 subnets
C 32.1.9.10 is directly connected, Virtual-Access10
C 32.1.9.241 is directly connected, Loopback9
c72d9-1#sh ip route vrf V1.9.com stat
U 192.168.200.0/24 [1/0] via 32.1.9.10
V1.9.com is the VRf to which the PPP session belongs
U means per-user static route ( a route downloaded via AAA)
RADIUS server# show debug
General OS:
AAA Authentication debugging is on
AAA Authorization debugging is on
AAA Per-user attributes debugging is on
Radius protocol debugging is on
Radius packet protocol debugging is on
03:01:48: AAA/AUTHEN/PPP (00000001): Pick method list 'default'
03:01:48: RADIUS/ENCODE(00000001): acct_session_id: 23
03:01:48: RADIUS(00000001): sending
03:01:48: RADIUS: Send to unknown id 21 40.40.40.40:1645, Access-Request, len
12
2
03:01:48: RADIUS: authenticator 28 70 0F 52 08 58 19 B4 - BE 26 71 53 D1 61 17
C6
03:01:48: RADIUS: User-Name [1] 16 "827@FRtest.com"
03:01:48: RADIUS: CHAP-Password [3] 19 *
03:01:48: RADIUS: NAS-Port [5] 6 1
03:01:48: RADIUS: Vendor, Cisco [26] 33
03:01:48: RADIUS: Cisco AVpair [1] 27 "interface=Virtual-Access1"
03:01:48: RADIUS: NAS-Port-Type [61] 6 Virtual [5]
03:01:48: RADIUS: Service-Type [6] 6 Framed [2]
03:01:48: RADIUS: NAS-IP-Address [4] 6 40.100.100.1
03:01:48: RADIUS: Acct-Session-Id [44] 10 "00000017"
03:01:48: RADIUS: Received from id 21 40.40.40.40:1645, Access-Accept, len 165
03:01:48: RADIUS: authenticator 1E D4 FB 0D 2D 7C 0E 0A - 6A 4D 83 11 DD
4D 50
AF
03:01:48: RADIUS: Service-Type [6] 6 Framed [2]
03:01:48: RADIUS: Framed-Protocol [7] 6 PPP [1]
03:01:48: RADIUS: Framed-IP-Address [8] 6 40.8.8.1
03:01:48: RADIUS: Framed-IP-Netmask [9] 6 255.255.255.224
03:01:48: RADIUS: Framed-Routing [10] 6 0
03:01:48: RADIUS: Vendor, Cisco [26] 60
03:01:48: RADIUS: Cisco AVpair [1] 54 "lcp:interface-config#1= ip vrf
forwarding FRtest.com"
03:01:48: RADIUS: Vendor, Cisco [26] 55
03:01:48: RADIUS: Cisco AVpair [1] 49 "lcp:interface-config#2= ip unn
umbered loopback1"
03:01:48: RADIUS: Received from id 1
03:01:48: Vi1 PPP/AAA: Check Attr: service-type
03:01:48: Vi1 PPP/AAA: Check Attr: Framed-Protocol
03:01:48: Vi1 PPP/AAA: Check Attr: addr
03:01:48: Vi1 PPP/AAA: Check Attr: route:Peruser
03:01:48: Vi1 PPP/AAA: Check Attr: netmask
03:01:48: Vi1 PPP/AAA: Check Attr: routing
03:01:48: Vi1 PPP/AAA: Check Attr: interface-config:Peruser I/F
03:01:48: Vi1 PPP/AAA: Check Attr: interface-config:Peruser I/F
03:01:48: Vi1 AAA/AUTHOR/LCP: Process Author
03:01:48: Vi1 AAA/AUTHOR/LCP: Vaccess Required for PER USER attrs
03:01:48: Vi1 AAA/AUTHOR/LCP: Process Attr: interface-config
03:01:48: AAA/AUTHOR: Processing PerUser AV interface-config
03:01:48: Vi1 AAA/AUTHOR/LCP: Process Attr: interface-config
03:01:48: AAA/AUTHOR: Processing PerUser AV interface-config
03:01:48: Vi1 AAA/AUTHOR/LCP: IF_config:
ip vrf forwarding FRtest.com
ip unnumbered loopback1
03:01:48: RADIUS/ENCODE(00000001): Unsupported AAA attribute timezone
03:01:48: RADIUS(00000001): sending
03:01:48: RADIUS: Send to unknown id 42 40.40.40.40:1646, Accounting-Request,
le
n 159
03:01:48: RADIUS: authenticator 29 02 40 0E 83 FE 2B 4A - F0 53 32 DC CF 66
0A
EA
03:01:48: RADIUS: Vendor, Cisco [26] 32
03:01:48: RADIUS: Cisco AVpair [1] 26 "connect-progress=Call Up"
03:01:48: RADIUS: User-Name [1] 16 "827@FRtest.com"
03:01:48: RADIUS: Acct-Status-Type [40] 6 Start [1]
03:01:48: RADIUS: Acct-Session-Id [44] 10 "00000017"
03:01:48: RADIUS: Framed-Protocol [7] 6 PPP [1]
03:01:48: RADIUS: Authentic [45] 6 RADIUS [1]
03:01:48: RADIUS: NAS-Port [5] 6 1
03:01:48: RADIUS: Vendor, Cisco [26] 33
03:01:48: RADIUS: Cisco AVpair [1] 27 "interface=Virtual-Access1"
03:01:48: RADIUS: NAS-Port-Type [61] 6 Virtual [5]
03:01:48: RADIUS: Service-Type [6] 6 Framed [2]
03:01:48: RADIUS: NAS-IP-Address [4] 6 40.100.100.1
03:01:48: RADIUS: Delay-Time [41] 6 0
03:01:48: Vi1 AAA/AUTHOR/IPCP: Already authorized
03:01:48: Vi1 AAA/AUTHOR/FSM: We can start IPCP
03:01:48: Vi1 AAA/AUTHOR/IPCP: Start. Her address 40.8.8.1, we want 0.0.0.0
03:01:48: Vi1 AAA/AUTHOR/IPCP: Processing AV addr
03:01:48: Vi1 AAA/AUTHOR/IPCP: Processing AV route
03:01:48: Vi1 AAA/AUTHOR/IPCP: Processing AV netmask
03:01:48: Vi1 AAA/AUTHOR/IPCP: Processing AV routing
03:01:48: Vi1 AAA/AUTHOR/IPCP: Set routing to FALSE
03:01:48: Vi1 AAA/AUTHOR/IPCP: Authorization succeeded
03:01:48: Vi1 AAA/AUTHOR/IPCP: Done. Her address 40.8.8.1, we want 40.8.8.1
03:01:48: Vi1 AAA/AUTHOR/IPCP: no author-info for primary dns
03:01:48: Vi1 AAA/AUTHOR/IPCP: no author-info for primary wins
03:01:48: Vi1 AAA/AUTHOR/IPCP: no author-info for seconday dns
03:01:48: Vi1 AAA/AUTHOR/IPCP: no author-info for seconday wins
03:01:48: RADIUS: Received from id 42 40.40.40.40:1646, Accounting-response, len
20
03:01:48: RADIUS: authenticator 2A F5 ED C9 72 03 34 BF - BD D4 BE 04 5F A5
E9
04
03:01:48: AAA/AUTHOR: Processing PerUser AV route
03:01:48: Vi1 AAA/PERUSER/ROUTE: vrf name for vaccess: FRtest.com
03:01:48: Vi1 AAA/PERUSER/ROUTE: route string: ip route vrf FRtest.com
40.8.8.0
255.255.255.224 40.8.8.1
In on-demand address pools (ODAP), a central SP RADIUS server manages a block of addresses for each customer. Each pool is divided into subnets of various sizes, and the server assigns subnets to the VHG/PE or NAS/PE on request.
The VHG/PE or NAS/PE acts as a DHCP server. On the VHG/PE or NAS/PE, one on-demand pool is configured for each customer VPN supported by that router. Upon configuration, the VHG/PE or NAS/PE's pool manager requests an initial subnet from the server.
Address management is on demand because address pool subnets are allocated or released based on a threshold. If use exceeds a defined ceiling threshold, the pool manager requests an additional subnet from the server and adds it to the on-demand pool. If use falls below a floor threshold, the pool manager attempts to free one, or more then one, of the on-demand pool's subnets to return it to the server. The VRF routing table on the VHG/PE or NAS/PE is updated with the subnet route whenever a range of addresses is requested from the AR.
If a problem occurs in ODAP, use the commands shown in Table 3-6 on the VHG/PE or NAS/PE. Example 3-41 shows the results of show up dhcp pool and Example 3-42 shows the results of debug ip dhcp server events.
Command | Use To... |
---|---|
show ip dhcp pool <address pool name>
| Check that DHCP pool hands out IP addresses for incoming PPP session and puts it in the correct VRF. |
debug ip dhcp server events | Report server events such as address assignments. |
Router# show ip dhcp pool odap-test
Pool odap-test : Utilization mark (high/low) : 80 / 20 Subnet size (first/next) :
27 / 27 (autogrow) VRF name : V1.1.com Total addresses
: 30 Leased addresses : 0 Pending requests : 0 1 subnet is
currently in the pool :Current index IP address range Leased addresses
42.1.1.1 42.1.1.1 - 42.1.1.30
Router# debug ip dhcp server events
DHCPD: allocate request for client U1000N1P3V1.1@V1.1.com on Virtual-Access7. DHCPD: locate VRF V1.1.com pool odap-test for client U1000N1P3V1.1@V1.1.com. DHCPD: assigned IP address 42.1.1.1 to client 5531.3030.304e.3150.3356.312e.3140.5631.2e31.2e63.6f6d.
Posted: Sun Sep 29 17:41:44 PDT 2002
All contents are Copyright © 1992--2002 Cisco Systems, Inc. All rights reserved.
Important Notices and Privacy Statement.