cc/td/doc/product/vpn/solution/rampls2
hometocprevnextglossaryfeedbacksearchhelp
PDF

Table of Contents

Troubleshooting DSL Access to MPLS VPN Integration

Troubleshooting DSL Access to MPLS VPN Integration

Chapter Overview

This chapter contains the following information about integrated Digital Subscriber Line (DSL) access to Multiprotocol Label Switching (MPLS) Virtual Private Network (VPN):

RFC 1483 Routing to MPLS VPN Integration

This section contains the following troubleshooting topics:

Overview of DSL RFC 1483 Routing to MPLS VPN Integration

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.


Figure 3-1: DSL RFC 1483 Routing


Initiating and Viewing debug Command Output

For reminders on using the command line interface for viewing debug output, refer to "Initiating and Viewing Command Output" section.

Debugging Problems Associated with RFC 1483 Routing Integration

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.


Table 3-1: Troubleshooting Cross-References for 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.

RFC 1483 PVC Connected (Step 1)

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.

DHCP Server Provides Address Assignment (Step 2)

RFC 1483 PVC Connected (Step 1)

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.


Example 3-1:
RFC 1483 Routed PDU LLC (bytes 1 - 3) - [0xAA-AA-03] OUI (bytes 4 - 6) - [0x00-00-00] EtherType (bytes 7 - 8) - [0x08-00] payload
Example 3-2:
Bridged (802.3-Specific) RFC 1483 PDU 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.


Example 3-3: Sample Debug RFC 1483 PVC Connected 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.


Example 3-4: Sample debug ip Command Output 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.

DHCP Server Provides Address Assignment (Step 2)

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.


Example 3-5: Sample Debug Address Assignment 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#

Verifying Correct Configuration for RFC 1483 Routing to MPLS VPN Integration

The following show commands are useful in debugging RFC 1483:

The following examples show the output from these show commands.


Example 3-6: Sample show ip route vrf <vpn> Command Output 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
Example 3-7: Sample show interfaces atm <interface> Command Output 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
Example 3-8:
Sample show atm map Command Output 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
Example 3-9:
Sample show atm vc Command Output 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

RFC 1483 Routed Bridge Encapsulation to MPLS VPN Integration

This section contains the following troubleshooting topics:

Overview of RBE to MPLS VPN Integration

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.


Figure 3-2: Cisco VPN DSL RBE to MPLS Integration


RBE References

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

Initiating and Viewing debug Command Output

For reminders on using the command line interface for viewing debug output, refer to "Initiating and Viewing Command Output" section.

Debugging Problems Associated with RBE to MPLS VPN Integration

Table 3-2 corresponds to Figure 3-2, providing a cross-reference to the debugging topics contained in this section.


Table 3-2: Troubleshooting RFC 1483 RBE to MPLS VPN Call Flow
Call Flow Step Related Troubleshooting Topic(s):

Step 1. RFC 1483 permanent virtual circuit (PVC) connected between DSL router and provider edge (PE) device.

RFC 1483 PVC Connected (Step 1)

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.

DHCP Server Provides Address Assignment (Step 2)

PVC Connected (Step 1)

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.


Example 3-10:
Bridged (802.3-Specific) RFC 1483 PDU 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.


Example 3-11: Sample Debug RFC 1483 PVC Connected 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.


Example 3-12: Sample debug ip Command Output 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.

DHCP Server Provides Address Assignment (Step 2)

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.


Example 3-13: Sample Debug Address Assignment 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

Verifying Correct Configuration for RBE to MPLS VPN Integration

The following show commands are useful in debugging RBE to MPLS VPN integration:

The following examples show the output from these show commands.


Example 3-14: Sample show ip route vrf <vpn> Command Output 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
Example 3-15: Sample show interfaces atm <interface> Command Output 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
Example 3-16: Sample show atm vc Command Output 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

PPPoX Remote Access to MPLS VPN Integration

This section contains the following troubleshooting topics:

Overview of DSL PPPOX Remote Access to MPLS VPN Integration

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.


Figure 3-3: DSL PPPoX


Initiating and Viewing debug command Output

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

Debugging Problems Associated with PPPoX Remote Access to MPLS VPN Integration

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).


Table 3-3: Troubleshooting Topics for DSL PPPOX to MPLS VPN Integration
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.

DSL Router Initiates a PPPoA Session (Step 1 and Step 2)

Remote User Initiates a PPPoE Session (Step 1 and Step 2)

Lines 3-4: VHG/PE queries SP RADIUS server and completes the remote user's authentication via RADIUS.

VHG/PE Queries SP RADIUS Server (Step 3 and Step 4[a])

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.

VHG/PE Obtains IP Address (Step 5)

DSL Router Initiates a PPPoA Session (Step 1 and Step 2)

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.


Example 3-17: Sample Debug DSL Router Cannot Initiate PPPoA Session 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#

Remote User Initiates a PPPoE Session (Step 1 and Step 2)

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.


Example 3-18: Sample Debug DSL Router Cannot Initiate PPPoE Session 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

VHG/PE Queries SP RADIUS Server (Step 3 and Step 4[a])

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.


Example 3-19: Sample Debug VHG/PE Queries SP RADIUS Server 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

Remote User Is Associated with a Specific Customer MPLS VPN (Step 3 and Step 4[b])

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.


Example 3-20: Sample Debug Remote User Is Associated with a Specific Customer MPLS VPN 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#

VHG/PE Obtains IP Address (Step 5)

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.


Example 3-21: Sample Debug VHG/PE Obtains IP Address 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

Verifying Correct Configuration for PPPoX Remote Access to MPLS VPN Integration

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.


Example 3-22: Sample show Command Output for PPPoX Remote Access to MPLS VPN Integration 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#

PPPoX Remote Access SSG to MPLS VPN Integration

This section contains the following troubleshooting topics:

Overview of DSL PPPOX Remote Access SSG to MPLS VPN Integration

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.


Figure 3-4: DSL PPPoX Remote Access


Initiating and Viewing debug Command Output

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

Debugging Problems Associated with PPPoX Remote Access SSG to MPLS VPN Integration

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.


Table 3-4: Troubleshooting Topics for DSL PPPOX to MPLS VPN Integration
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.

SSG Obtains an IP Address (Step 5)

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.

SSG User Selects a Service From SSD (Step 11)

DSL Router Cannot Initiate PPPoX Session (Step 1 and Step 2)

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.


Example 3-23: Sample Debug DSL Router Cannot Initiate PPPoX Session 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#

SSG Queries the RADIUS Server (Step 3 and Step 4[a])


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.


Example 3-24: Sample Debug SSG Queries the RADIUS Server 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#

SSG Completes the Remote User's Authentication (Step 3 and Step 4[b])

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.


Example 3-25: Sample Debug SSG Completes the Remote User's Authentication 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#

SSG Obtains an IP Address (Step 5)

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.


Example 3-26: Sample Debug SSG Obtains an IP Address 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

SSG User Browses SSD and Authenticates (Step 6 through Step 10)

The remote user accesses the Service Selection Dashboard (SSD) using a web client pointing to SSD; the user is authenticated. SSG creates a host object for the remote user. Once authenticated, the web page is updated to reflect the services the user is authorized to access and initially only obtains default service, if defined.

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.


Example 3-27: Sample Debug SSG User Browses SSD and Authenticates—ssg events and ssg ctrl-events 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.
Example 3-28:
Sample Debug SSG User Browses SSD and Authenticates—RADIUS 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#

SSG User Selects a Service From SSD (Step 11)

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.


Example 3-29: Sample Debug SSG User Selects a Service from SSD—ssg events and ssg ctrl-events 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#
Example 3-30:
Sample Debug SSG User Selects a Service From SSD—RADIUS [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#

Verifying Correct Configuration for PPPoX Remote Access SSG to MPLS VPN Integration

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.


Example 3-31: Sample show Command Output for PPPoX Remote Access SSG to MPLS VPN Integration 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

L2TP to MPLS VPN Integration

This section contains the following troubleshooting topics:

Overview of DSL L2TP to MPLS VPN Integration

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.


Figure 3-5:
DSL L2TP


Initiating and Viewing debug Command Output

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

Debugging Problems Associated with DSL L2TP to MPLS VPN Integration

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.


Table 3-5: Troubleshooting Topics for 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.

Accept Connection (Step 2)

Line 3: NAS partially authenticates the user with CHAP or PAP and obtains tunnel information.

Authenticate and Obtain Tunnel Information (Step 3)

Line 4: NAS initiates a tunnel to the VHG-PE/LNS (if L2TP tunnel does not exist).

Establish L2TP Tunnel (Step 4)

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.

Complete PPP Authentication (Step 5 through Step 10[b])

Accept Connection (Step 2)

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.


Example 3-32: Sample Debug Accept Connection [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

Authenticate and Obtain Tunnel Information (Step 3)

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.


Example 3-33: Sample Debug Authenticate and Obtain Tunnel Information 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#

Establish L2TP Tunnel (Step 4)

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.


Example 3-34: Sample Debug Establish L2TP Tunnel [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#

Create Tunnel Session and Propagate PPP Information (Step 5 through Step 10[a])

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.


Example 3-35: Sample Debug Create Tunnel Session and Propagate PPP Information [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#

Complete PPP Authentication (Step 5 through Step 10[b])

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.


Example 3-36: Sample Debug Complete PPP Authentication [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#

Verifying Correct Configuration for DSL L2TP to MPLS VPN Integration

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

show Commands for NAS

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.


Example 3-37: Sample show Command Output for NAS [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

show Commands for VHG-PE/LNS

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.


Example 3-38: Sample show Command Output for VHG-PE/LNS 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

Troubleshooting Specific Features

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

Troubleshooting the Framed-Route VRF Aware Feature

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


Example 3-39: Example of VHG/PE show ip route Command Output 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)
Example 3-40: Example of RADIUS debug Command Output

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

Verifying and Troubleshooting On-demand Address Pools

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.


Table 3-6: show and debug Commands for ODAP
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.


Example 3-41:
Sample Results of show ip dhcp pool for Troubleshooting ODAP 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
Example 3-42:
Sample Results of debug ip dhcp server events for Troubleshooting ODAP 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.


hometocprevnextglossaryfeedbacksearchhelp
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.