MLPPP over VPDN Configuration Example

Introduction

This article describes the configuration of Client , Layer 2 Tunnelling Protocol Access Concentrator (LAC) and Layer 2 Tunnelling Protocol Network Server (LNS) that helps to bring up a Multilink Point-to-Point Protocol (MLPPP) session between Client and LNS built over a Virtual Private Dial-up Network (VPDN) tunnel.

Prerequisites

Requirements

Cisco recommends that you meet these requirements before you attempt this configuration:  

• End-to-End Layer 1 connectivity is UP

Components Used

This document is not restricted to specific software and hardware versions.

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.

Configure

Note: Use the Command Lookup Tool (registered customers only) in order to obtain more information on the commands used in this section.

Network Diagram

Configurations

Note: In the case of PPP control packet exchanges during PPP or Multilink PPP session initiation time, the Multilink PPP session is negotiated between the CPE and the LNS, not with the LAC. The LAC does not have the knowledge about the Multilink PPP session. As a result, when the CPE initiates a PPP-LCP session, the Multilink (Maximum Receive Reconstructed Unit [MRRU]) negotiation included as part of the LCP negotiation may fail if the LAC has not yet established the connection with the LNS (which is typically the case). When the IP reachability between the LAC and the LNS is established, the LNS can renegotiate Multilink (MRRU) LCP options with the CPE, and the two peer devices can then establish an end-to-end Multilink PPP session.

Client Configuration:

An example of the configuration on the Client router is shown here:

interface Ethernet0/0

no ip address

pppoe enable group global

pppoe-client dial-pool-number 1

interface Dialer1

bandwidth 64

ip address negotiated

encapsulation ppp

dialer pool 1

dialer idle-timeout 0

keepalive 30

ppp max-failure 30

ppp chap hostname user@cisco.com

ppp chap password cisco

ppp multilink

no cdp enable

LAC Configuration:

An example of the configuration on the LAC router is shown here:

hostname LAC

!

vpdn enable

!

vpdn-group 1

request-dialin

protocol l2tp

domain cisco.com

initiate-to ip 192.168.1.2

no l2tp tunnel authentication

!

bba-group pppoe global

virtual-template 1

!

interface Ethernet0/0

no ip address

pppoe enable group global

interface Ethernet1/0

ip address 192.168.1.1 255.255.255.0

interface Virtual-Template1

no ip address

ppp authentication chap

ppp multilink

LNS Configuration:

An example of the configuration on the LNS router is shown here:

vpdn enable

!

vpdn-group 1

accept-dialin

protocol l2tp

virtual-template 1

terminate-from hostname LAC

lcp renegotiation on-mismatch

no l2tp tunnel authentication

!

username user@cisco.com password cisco

int loopback0

ip address 10.10.10.10 255.255.255.0

interface Ethernet1/0

ip address 192.168.1.2 255.255.255.0

interface Virtual-Template1

mtu 1492

ip unnumbered Loopback0

peer default ip address pool cisco

ppp authentication chap

ppp multilink

!

ip local pool cisco 10.10.10.11 10.10.10.24

Verify

Following debugs are enabled on Client, LAC and LNS:

• Debug ppp negotiation
• Debug pppoe event
• Debug ppp multilink event
• Debug vpdn event
• Debug vpdn call event

Client Logs:

*Jan 14 11:01:12.744: Sending PADI: Interface = Ethernet0/0
*Jan 14 11:01:12.744: PPPoE 0: I PADO R:aabb.cc02.bd00 L:aabb.cc02.bc00 Et0/0
*Jan 14 11:01:14.824: PPPOE: we've got our pado and the pado timer went off
*Jan 14 11:01:14.824: OUT PADR from PPPoE Session
*Jan 14 11:01:14.825: PPPoE 9: I PADS R:aabb.cc02.bd00 L:aabb.cc02.bc00 Et0/0
*Jan 14 11:01:14.825: IN PADS from PPPoE Session
*Jan 14 11:01:14.825: %DIALER-6-BIND: Interface Vi3 bound to profile Di1
*Jan 14 11:01:14.825: PPPoE: Virtual Access interface obtained.
*Jan 14 11:01:14.825: PPPoE : encap string prepared
*Jan 14 11:01:14.825: [0]PPPoE 9: data path set to PPPoE Client
*Jan 14 11:01:14.834: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up
*Jan 14 11:01:14.834: Vi3 PPP: Sending cstate UP notification
*Jan 14 11:01:14.834: Vi3 PPP: Processing CstateUp message
*Jan 14 11:01:14.834: PPP: Alloc Context [2A970D92E8]
*Jan 14 11:01:14.834: ppp14 PPP: Phase is ESTABLISHING
*Jan 14 11:01:14.834: Vi3 PPP: Using dialer call direction
*Jan 14 11:01:14.834: Vi3 PPP: Treating connection as a callout
*Jan 14 11:01:14.834: Vi3 PPP: Session handle[C2000013] Session id[14]
*Jan 14 11:01:14.834: Vi3 LCP: Event[OPEN] State[Initial to Starting]
*Jan 14 11:01:14.834: Vi3 PPP: No remote authentication for call-out
*Jan 14 11:01:14.834: Vi3 LCP: O CONFREQ [Starting] id 1 len 30
*Jan 14 11:01:14.834: Vi3 LCP:   MagicNumber 0xBC220EF6 (0x0506BC220EF6)
*Jan 14 11:01:14.835: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.835: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.835: Vi3 LCP: Event[UP] State[Starting to REQsent]
*Jan 14 11:01:14.835: Vi3 LCP: I CONFREQ [REQsent] id 1 len 29
*Jan 14 11:01:14.835: Vi3 LCP:   MRU 1492 (0x010405D4)
*Jan 14 11:01:14.835: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.835: Vi3 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)
*Jan 14 11:01:14.835: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.835: Vi3 LCP:   EndpointDisc 1 LAC (0x1306014C4143)
*Jan 14 11:01:14.835: Vi3 LCP: O CONFNAK [REQsent] id 1 len 8
*Jan 14 11:01:14.835: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.835: Vi3 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]
*Jan 14 11:01:14.835: Vi3 LCP: I CONFACK [REQsent] id 1 len 30
*Jan 14 11:01:14.835: Vi3 LCP:   MagicNumber 0xBC220EF6 (0x0506BC220EF6)
*Jan 14 11:01:14.835: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.835: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.835: Vi3 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Jan 14 11:01:14.836: Vi3 LCP: I CONFREQ [ACKrcvd] id 2 len 29
*Jan 14 11:01:14.836: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.836: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.836: Vi3 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)
*Jan 14 11:01:14.836: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.836: Vi3 LCP:   EndpointDisc 1 LAC (0x1306014C4143)
*Jan 14 11:01:14.836: Vi3 LCP: O CONFACK [ACKrcvd] id 2 len 29
*Jan 14 11:01:14.836: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.836: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.836: Vi3 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)
*Jan 14 11:01:14.836: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.836: Vi3 LCP:   EndpointDisc 1 LAC (0x1306014C4143)
*Jan 14 11:01:14.836: Vi3 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Jan 14 11:01:14.854: Vi3 PPP: Phase is AUTHENTICATING, by the peer
*Jan 14 11:01:14.854: Vi3 LCP: State is Open
*Jan 14 11:01:14.856: Vi3 CHAP: I CHALLENGE id 1 len 24 from "LAC"
*Jan 14 11:01:14.856: Vi3 CHAP: Using hostname from interface CHAP
*Jan 14 11:01:14.856: Vi3 CHAP: Using password from interface CHAP
*Jan 14 11:01:14.856: Vi3 CHAP: O RESPONSE id 1 len 34 from "user@cisco.com"
*Jan 14 11:01:14.861: Vi3 LCP: I CONFREQ [Open] id 1 len 39
*Jan 14 11:01:14.861: Vi3 LCP:   MRU 1492 (0x010405D4)
*Jan 14 11:01:14.861: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.861: Vi3 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)
*Jan 14 11:01:14.861: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.861: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.861: Vi3 PPP DISC: PPP Renegotiating
*Jan 14 11:01:14.861: PPP: NET STOP send to AAA.
*Jan 14 11:01:14.861: Vi3 LCP: Event[LCP Reneg] State[Open to Open]
*Jan 14 11:01:14.861: Vi3 LCP: Event[DOWN] State[Open to Starting]
*Jan 14 11:01:14.861: Vi3 PPP: Phase is DOWN
*Jan 14 11:01:14.861: PPP: Alloc Context [2A970D9898]
*Jan 14 11:01:14.861: ppp14 PPP: Phase is ESTABLISHING
*Jan 14 11:01:14.861: Vi3 PPP: Using dialer call direction
*Jan 14 11:01:14.861: Vi3 PPP: Treating connection as a callout
*Jan 14 11:01:14.861: Vi3 PPP: Session handle[2B000014] Session id[14]
*Jan 14 11:01:14.861: Vi3 LCP: Event[OPEN] State[Initial to Starting]
*Jan 14 11:01:14.861: Vi3 PPP: No remote authentication for call-out
*Jan 14 11:01:14.861: Vi3 LCP: O CONFREQ [Starting] id 1 len 30
*Jan 14 11:01:14.861: Vi3 LCP:   MagicNumber 0xBC220F12 (0x0506BC220F12)
*Jan 14 11:01:14.861: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.861: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.862: Vi3 LCP: Event[UP] State[Starting to REQsent]
*Jan 14 11:01:14.862: Vi3 LCP: I CONFREQ [REQsent] id 1 len 39
*Jan 14 11:01:14.862: Vi3 LCP:   MRU 1492 (0x010405D4)
*Jan 14 11:01:14.862: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.862: Vi3 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)
*Jan 14 11:01:14.862: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.862: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.862: Vi3 PPP: Remote endpoint user@cisco.com invalid, matches local value
*Jan 14 11:01:14.862: Vi3 LCP: O CONFNAK [REQsent] id 1 len 8
*Jan 14 11:01:14.862: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.862: Vi3 LCP: Event[Receive ConfReq-] State[REQsent to REQsent]
*Jan 14 11:01:14.862: Vi3 LCP: I CONFACK [REQsent] id 1 len 30
*Jan 14 11:01:14.862: Vi3 LCP:   MagicNumber 0xBC220F12 (0x0506BC220F12)
*Jan 14 11:01:14.862: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.862: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.862: Vi3 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Jan 14 11:01:14.862: Vi3 LCP: I CONFREQ [ACKrcvd] id 2 len 39
*Jan 14 11:01:14.862: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.862: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.862: Vi3 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)
*Jan 14 11:01:14.862: Vi3 LCP:   MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.862: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.862: Vi3 PPP: Remote endpoint user@cisco.com invalid, matches local value
*Jan 14 11:01:14.862: Vi3 LCP: O CONFACK [ACKrcvd] id 2 len 39
*Jan 14 11:01:14.862: Vi3 LCP:   MRU 1500 (0x010405DC)
*Jan 14 11:01:14.862: Vi3 LCP:   AuthProto CHAP (0x0305C22305)
*Jan 14 11:01:14.862: Vi3 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)
*Jan 14 11:01:14.862: Vi3 LCP:    MRRU 1524 (0x110405F4)
*Jan 14 11:01:14.862: Vi3 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)
*Jan 14 11:01:14.862: Vi3 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Jan 14 11:01:14.884: Vi3 PPP: Phase is AUTHENTICATING, by the peer
*Jan 14 11:01:14.884: Vi3 LCP: State is Open
*Jan 14 11:01:14.895: Vi3 CHAP: I CHALLENGE id 2 len 27 from "LNS"
*Jan 14 11:01:14.895: Vi3 CHAP: Using hostname from interface CHAP
*Jan 14 11:01:14.895: Vi3 CHAP: Using password from interface CHAP
*Jan 14 11:01:14.895: Vi3 CHAP: O RESPONSE id 2 len 34 from "user@cisco.com"
*Jan 14 11:01:14.896: Vi3 CHAP: I SUCCESS id 2 len 4
*Jan 14 11:01:14.896: Vi3 PPP: Phase is FORWARDING, Attempting Forward
*Jan 14 11:01:14.897: Vi3 PPP: Phase is ESTABLISHING, Finish LCP
*Jan 14 11:01:14.897: Vi3 MLP: Request add link to bundle
*Jan 14 11:01:14.897: Vi3 PPP: Phase is VIRTUALIZED
*Jan 14 11:01:14.897: Vi3 MLP: Adding link to bundle
*Jan 14 11:01:14.897: Vi3 MLP: Requested bundle vaccess creation
*Jan 14 11:01:14.897: Vi3 MLP: Determine clone source for SSS
*Jan 14 11:01:14.897: Vi3 MLP: Clone from dialer profile Di1
*Jan 14 11:01:14.897: Vi3 MLP: Determine clone source for SSS
*Jan 14 11:01:14.897: Vi3 MLP: Clone from dialer profile Di1
*Jan 14 11:01:14.897: Vi3 MLP: SSS connect, bundle interface Vi4
*Jan 14 11:01:14.897: PPP: Alloc Context [2A970D95C0]
*Jan 14 11:01:14.897: ppp15 PPP: Phase is ESTABLISHING
*Jan 14 11:01:14.897: Vi4 MLP: Changing bundle bandwidth from 100000 to 64
*Jan 14 11:01:14.897: Vi4 MLP: Bandwidth manually configured, updating lost frag timeout on bundle
*Jan 14 11:01:14.897: Vi4 MLP: Increasing lost frag timeout from 100 to 1524 ms due to slippage constraints
*Jan 14 11:01:14.897: Vi4 MLP: Increasing lost frag timeout from 100 to 1524 ms due to slippage constraints
*Jan 14 11:01:14.897: %DIALER-6-BIND: Interface Vi4 bound to profile Di1
*Jan 14 11:01:14.897: Vi4 MLP: Added to dialer pool Di1
*Jan 14 11:01:14.897: Vi4 MLP: Ready to finish adding link Vi3 to bundle
*Jan 14 11:01:14.897: Vi4 MLP: Update bundle bandwidth 64 set 64
*Jan 14 11:01:14.897: Vi3 MLP: Change transmit status from Init to Enabled, transmit links 1
*Jan 14 11:01:14.897: Vi4 MLP: Idle timer running, restart
*Jan 14 11:01:14.897: Vi4 MLP: Added first link Vi3 to bundle LNS
*Jan 14 11:01:14.897: Vi4 MLP: Increasing lost frag timeout from 100 to 1524 ms due to slippage constraints
*Jan 14 11:01:14.898: Vi3 MLP: Updating bundle's PPP handle[0x6F000015] in SSS context
*Jan 14 11:01:14.898: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up
*Jan 14 11:01:14.898: Vi4 MLP: Received segment updated message for bundle
*Jan 14 11:01:14.914: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to up
*Jan 14 11:01:14.914: Vi4 PPP: Force LCP OPEN on MLP Bundle
*Jan 14 11:01:14.914: Vi4 PPP: Phase is UP
*Jan 14 11:01:14.914: Vi4 IPCP: Protocol configured, start CP. state[Initial]
*Jan 14 11:01:14.914: Vi4 IPCP: Event[OPEN] State[Initial to Starting]
*Jan 14 11:01:14.914: Vi4 IPCP: O CONFREQ [Starting] id 1 len 10
*Jan 14 11:01:14.914: Vi4 IPCP:   Address 0.0.0.0 (0x030600000000)
*Jan 14 11:01:14.914: Vi4 IPCP: Event[UP] State[Starting to REQsent]
*Jan 14 11:01:14.915: Vi4 IPCP: I CONFREQ [REQsent] id 1 len 10
*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.10 (0x03060A0A0A0A)
*Jan 14 11:01:14.915: Vi4 IPCP: O CONFACK [REQsent] id 1 len 10
*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.10 (0x03060A0A0A0A)
*Jan 14 11:01:14.915: Vi4 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent]
*Jan 14 11:01:14.915: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to up
*Jan 14 11:01:14.915: Vi4 IPCP: I CONFNAK [ACKsent] id 1 len 10
*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)
*Jan 14 11:01:14.915: Vi4 IPCP: O CONFREQ [ACKsent] id 2 len 10
*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)
*Jan 14 11:01:14.915: Vi4 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
*Jan 14 11:01:14.936: Vi4 IPCP: I CONFACK [ACKsent] id 2 len 10
*Jan 14 11:01:14.936: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)
*Jan 14 11:01:14.936: Vi4 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
*Jan 14 11:01:14.954: Vi4 IPCP: State is Open
*Jan 14 11:01:14.954: Di1 IPCP: Install negotiated IP interface address 10.10.10.18
*Jan 14 11:01:14.954: Di1 Added to neighbor route AVL tree: topoid 0, address 10.10.10.10
*Jan 14 11:01:14.954: Di1 IPCP: Install route to 10.10.10.10

Client#show ppp all

Interface/ID OPEN+ Nego* Fail-     Stage   Peer Address   Peer Name

------------ --------------------- -------- --------------- --------------------

Vi4         IPCP+                 LocalT   10.10.10.10     LNS       

Vi3         LCP+                 LocalT   10.10.10.10     LNS         

Client#show ppp multilink

Virtual-Access4

Bundle name: LNS

Remote Username: LNS

Remote Endpoint Discriminator: [1] user@cisco.com

Local Username: user@cisco.com

Local Endpoint Discriminator: [1] user@cisco.com

Bundle up for 00:00:17, total bandwidth 64, load 1/255

Receive buffer limit 12192 bytes, frag timeout 1524 ms

Dialer interface is Dialer1

   0/0 fragments/bytes in reassembly list

   0 lost fragments, 0 reordered

   0/0 discarded fragments/bytes, 0 lost received

   0x3 received sequence, 0x0 sent sequence

Member links: 1 (max 255, min not set)

   Vi3, since 00:00:17

No inactive multilink interfaces

LAC Logs:

*Jan 14 11:01:12.744: PPPoE 0: I PADI R:aabb.cc02.bc00 L:ffff.ffff.ffff Et0/0

*Jan 14 11:01:12.744: Service tag: NULL Tag

*Jan 14 11:01:12.744: PPPoE 0: O PADO, R:aabb.cc02.bd00 L:aabb.cc02.bc00 Et0/0

*Jan 14 11:01:12.744: Service tag: NULL Tag

*Jan 14 11:01:14.824: PPPoE 0: I PADR R:aabb.cc02.bc00 L:aabb.cc02.bd00 Et0/0

*Jan 14 11:01:14.824: Service tag: NULL Tag

*Jan 14 11:01:14.824: PPPoE : encap string prepared

*Jan 14 11:01:14.824: [9]PPPoE 9: Access IE handle allocated

*Jan 14 11:01:14.824: [9]PPPoE 9: AAA unique ID 17 allocated

*Jan 14 11:01:14.824: [9]PPPoE 9: No AAA accounting method list

*Jan 14 11:01:14.824: [9]PPPoE 9: Service request sent to SSS

*Jan 14 11:01:14.824: [9]PPPoE 9: Created, Service: None R:aabb.cc02.bd00 L:aabb.cc02.bc00 Et0/0

*Jan 14 11:01:14.825: [9]PPPoE 9: State NAS_PORT_POLICY_INQUIRY   Event SSS MORE KEYS

*Jan 14 11:01:14.825: PPP: Alloc Context [2A970D9898]

*Jan 14 11:01:14.825: ppp9 PPP: Phase is ESTABLISHING

*Jan 14 11:01:14.825: [9]PPPoE 9: data path set to PPP

*Jan 14 11:01:14.825: [9]PPPoE 9: Segment (SSS class): PROVISION

*Jan 14 11:01:14.825: [9]PPPoE 9: State PROVISION_PPP   Event SSM PROVISIONED

*Jan 14 11:01:14.825: [9]PPPoE 9: O PADS R:aabb.cc02.bc00 L:aabb.cc02.bd00 Et0/0

*Jan 14 11:01:14.825: ppp9 PPP: Using vpn set call direction

*Jan 14 11:01:14.825: ppp9 PPP: Treating connection as a callin

*Jan 14 11:01:14.825: ppp9 PPP: Session handle[B4000009] Session id[9]

*Jan 14 11:01:14.825: ppp9 LCP: Event[OPEN] State[Initial to Starting]

*Jan 14 11:01:14.825: ppp9 PPP LCP: Enter passive mode, state[Stopped]

*Jan 14 11:01:14.835: ppp9 LCP: I CONFREQ [Stopped] id 1 len 30

*Jan 14 11:01:14.835: ppp9 LCP:   MagicNumber 0xBC220EF6 (0x0506BC220EF6)

*Jan 14 11:01:14.835: ppp9 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.835: ppp9 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.835: ppp9 LCP: O CONFREQ [Stopped] id 1 len 29

*Jan 14 11:01:14.835: ppp9 LCP:   MRU 1492 (0x010405D4)

*Jan 14 11:01:14.835: ppp9 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.835: ppp9 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)

*Jan 14 11:01:14.835: ppp9 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.835: ppp9 LCP:   EndpointDisc 1 LAC (0x1306014C4143)

*Jan 14 11:01:14.835: ppp9 LCP: O CONFACK [Stopped] id 1 len 30

*Jan 14 11:01:14.835: ppp9 LCP:   MagicNumber 0xBC220EF6 (0x0506BC220EF6)

*Jan 14 11:01:14.835: ppp9 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.835: ppp9 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.835: ppp9 LCP: Event[Receive ConfReq+] State[Stopped to ACKsent]

*Jan 14 11:01:14.836: ppp9 LCP: I CONFNAK [ACKsent] id 1 len 8

*Jan 14 11:01:14.836: ppp9 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.836: ppp9 LCP: O CONFREQ [ACKsent] id 2 len 29

*Jan 14 11:01:14.836: ppp9 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.836: ppp9 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.836: ppp9 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)

*Jan 14 11:01:14.836: ppp9 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.836: ppp9 LCP:   EndpointDisc 1 LAC (0x1306014C4143)

*Jan 14 11:01:14.836: ppp9 LCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]

*Jan 14 11:01:14.836: ppp9 LCP: I CONFACK [ACKsent] id 2 len 29

*Jan 14 11:01:14.836: ppp9 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.836: ppp9 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.836: ppp9 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)

*Jan 14 11:01:14.836: ppp9 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.836: ppp9 LCP:   EndpointDisc 1 LAC (0x1306014C4143)

*Jan 14 11:01:14.836: ppp9 LCP: Event[Receive ConfAck] State[ACKsent to Open]

*Jan 14 11:01:14.856: ppp9 PPP: Phase is AUTHENTICATING, by this end

*Jan 14 11:01:14.856: ppp9 CHAP: O CHALLENGE id 1 len 24 from "LAC"

*Jan 14 11:01:14.856: ppp9 LCP: State is Open

*Jan 14 11:01:14.856: ppp9 CHAP: I RESPONSE id 1 len 34 from "user@cisco.com"

*Jan 14 11:01:14.856: ppp9 PPP: Phase is FORWARDING, Attempting Forward

*Jan 14 11:01:14.856: VPDN CALL [uid:9]: Requesting connection

*Jan 14 11:01:14.856: VPDN CALL [uid:9]: Call request sent

*Jan 14 11:01:14.857: [9]PPPoE 9: Access IE nas port called

*Jan 14 11:01:14.857: VPDN uid:9 Obtained connect speeds are TX(10000000) RX(10000000)

*Jan 14 11:01:14.857: VPDN uid:9 Obtained connect speeds are TX(10000000) RX(10000000)

*Jan 14 11:01:14.857: VPDN uid:9 L2TUN socket session connect requested for socket handle F600000C

*Jan 14 11:01:14.857: VPDN uid:9 Setting up dataplane for L2-L2, no idb

*Jan 14 11:01:14.857: VPDN MGR [uid:9]: Initiating compulsory connection to 192.168.1.2

*Jan 14 11:01:14.857: [9]PPPoE 9: State LCP_NEGOTIATION   Event PPP FORWARDING

*Jan 14 11:01:14.857: [9]PPPoE 9: Segment (SSS class): UPDATED

*Jan 14 11:01:14.857: [9]PPPoE 9: SSS switch updated

*Jan 14 11:01:14.859: VPDN Received L2TUN socket message Status

*Jan 14 11:01:14.859: VPDN uid:9 cannot find swidb for session

*Jan 14 11:01:14.859: [9]PPPoE 9: Segment (SSS class): BOUND

*Jan 14 11:01:14.859: [9]PPPoE 9: data path set to SSS Switch

*Jan 14 11:01:14.859: VPDN Received L2TUN socket message Connected

*Jan 14 11:01:14.859: VPDN MGR [uid:9]: Succeed to forward user@cisco.com

*Jan 14 11:01:14.859: VPDN uid:9 VPDN session up

*Jan 14 11:01:14.859: VPDN CALL [uid:9]: Connection succeeded

*Jan 14 11:01:14.860: ppp9 PPP: Phase is FORWARDED, Session Forwarded

*Jan 14 11:01:14.860: [9]PPPoE 9: State LCP_NEGOTIATION   Event PPP FORWARDED

*Jan 14 11:01:14.860: [9]PPPoE 9: Connected Forwarded

LAC#show ppp all

Interface/ID OPEN+ Nego* Fail-     Stage   Peer Address   Peer Name

------------ --------------------- -------- --------------- --------------------

0xB4000009   LCP+ CHAP*           Fwded   0.0.0.0         user@cisco.com  

LAC#show ppp multilink

No active bundles

No inactive multilink interfaces

LNS Logs:

*Jan 14 11:01:14.858: VPDN Received L2TUN socket message Incoming

*Jan 14 11:01:14.859: VPDN uid:13 L2TUN socket session accept requested

*Jan 14 11:01:14.859: VPDN uid:13 Setting up dataplane for L2-L2, no idb

*Jan 14 11:01:14.860: VPDN Received L2TUN socket message Connected

*Jan 14 11:01:14.860: VPDN uid:13 VPDN session up

*Jan 14 11:01:14.860: PPP: Alloc Context [2A970D95C0]

*Jan 14 11:01:14.860: ppp13 PPP: Phase is ESTABLISHING

*Jan 14 11:01:14.860: ppp13 LCP: Event[Jam Start] State[Initial to Closed]

*Jan 14 11:01:14.860: ppp13 LCP: I FORCED rcvd CONFACK len 29

*Jan 14 11:01:14.861: ppp13 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.861: ppp13 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.861: ppp13 LCP:   MagicNumber 0xBC21F6F0 (0x0506BC21F6F0)

*Jan 14 11:01:14.861: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.861: ppp13 LCP:   EndpointDisc 1 LAC (0x1306014C4143)

*Jan 14 11:01:14.861: ppp13 PPP: LCP not accepting rcv CONFACK

*Jan 14 11:01:14.861: ppp13 LCP: I FORCED sent CONFACK len 30

*Jan 14 11:01:14.861: ppp13 LCP:   MagicNumber 0xBC220EF6 (0x0506BC220EF6)

*Jan 14 11:01:14.861: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.861: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.861: ppp13 LCP: Event[DOWN] State[Closed to Initial]

*Jan 14 11:01:14.861: ppp13 LCP: Event[CLOSE] State[Initial to Initial]

*Jan 14 11:01:14.861: ppp13 LCP: Event[OPEN] State[Initial to Starting]

*Jan 14 11:01:14.861: ppp13 LCP: O CONFREQ [Starting] id 1 len 39

*Jan 14 11:01:14.861: ppp13 LCP:   MRU 1492 (0x010405D4)

*Jan 14 11:01:14.861: ppp13 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.861: ppp13 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)

*Jan 14 11:01:14.861: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.861: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.861: ppp13 LCP: Event[UP] State[Starting to REQsent]

*Jan 14 11:01:14.862: ppp13 LCP: I CONFREQ [REQsent] id 1 len 30

*Jan 14 11:01:14.862: ppp13 LCP:   MagicNumber 0xBC220F12 (0x0506BC220F12)

*Jan 14 11:01:14.862: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.862: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.862: ppp13 PPP: Remote endpoint user@cisco.com invalid, matches local value

*Jan 14 11:01:14.862: ppp13 LCP: O CONFACK [REQsent] id 1 len 30

*Jan 14 11:01:14.862: ppp13 LCP:   MagicNumber 0xBC220F12 (0x0506BC220F12)

*Jan 14 11:01:14.862: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.862: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.862: ppp13 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent]

*Jan 14 11:01:14.862: ppp13 LCP: I CONFNAK [ACKsent] id 1 len 8

*Jan 14 11:01:14.862: ppp13 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.862: ppp13 LCP: O CONFREQ [ACKsent] id 2 len 39

*Jan 14 11:01:14.862: ppp13 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.862: ppp13 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.862: ppp13 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)

*Jan 14 11:01:14.862: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.862: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.862: ppp13 LCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]

*Jan 14 11:01:14.863: ppp13 LCP: I CONFACK [ACKsent] id 2 len 39

*Jan 14 11:01:14.863: ppp13 LCP:   MRU 1500 (0x010405DC)

*Jan 14 11:01:14.863: ppp13 LCP:   AuthProto CHAP (0x0305C22305)

*Jan 14 11:01:14.863: ppp13 LCP:   MagicNumber 0xBC21E526 (0x0506BC21E526)

*Jan 14 11:01:14.863: ppp13 LCP:   MRRU 1524 (0x110405F4)

*Jan 14 11:01:14.863: ppp13 LCP:   EndpointDisc 1 user@cisco.com (0x1310017573657240737572662E6F7267)

*Jan 14 11:01:14.863: ppp13 LCP: Event[Receive ConfAck] State[ACKsent to Open]

*Jan 14 11:01:14.895: ppp13 PPP: Phase is AUTHENTICATING, by this end

*Jan 14 11:01:14.895: ppp13 CHAP: O CHALLENGE id 2 len 27 from "LNS"

*Jan 14 11:01:14.895: ppp13 LCP: State is Open

*Jan 14 11:01:14.895: ppp13 CHAP: I RESPONSE id 2 len 34 from "user@cisco.com"

*Jan 14 11:01:14.895: ppp13 PPP: Phase is FORWARDING, Attempting Forward

*Jan 14 11:01:14.895: ppp13 PPP: Phase is AUTHENTICATING, Unauthenticated User

*Jan 14 11:01:14.895: ppp13 PPP: Phase is FORWARDING, Attempting Forward

*Jan 14 11:01:14.896: VPDN uid:13 Virtual interface created for user@cisco.com bandwidth 10000 Kbps

*Jan 14 11:01:14.896: VPDN Vi3 Virtual interface created for user@cisco.com, bandwidth 10000 Kbps

L2X_ADJ: Vi3:allocated ctx, size 1

*Jan 14 11:01:14.896: VPDN Received L2TUN socket message Data UP

*Jan 14 11:01:14.896: Vi3 PPP: Phase is AUTHENTICATING, Authenticated User

*Jan 14 11:01:14.896: Vi3 CHAP: O SUCCESS id 2 len 4

*Jan 14 11:01:14.896: Vi3 MLP: Request add link to bundle

*Jan 14 11:01:14.896: Vi3 PPP: Phase is VIRTUALIZED

*Jan 14 11:01:14.896: Vi3 MLP: Adding link to bundle

*Jan 14 11:01:14.896: Vi3 MLP: Requested bundle vaccess creation

*Jan 14 11:01:14.896: Vi3 MLP: Determine clone source for SSS

*Jan 14 11:01:14.896: Vi3 MLP: Link is Virtual-Access, clone from Virtual-Template 1

*Jan 14 11:01:14.897: Vi3 MLP: Determine clone source for SSS

*Jan 14 11:01:14.897: Vi3 MLP: Link is Virtual-Access, clone from Virtual-Template 1

*Jan 14 11:01:14.897: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up

*Jan 14 11:01:14.897: Vi3 MLP: SSS connect, bundle interface Vi4

*Jan 14 11:01:14.897: PPP: Alloc Context [2A970D9898]

*Jan 14 11:01:14.897: ppp14 PPP: Phase is ESTABLISHING

*Jan 14 11:01:14.897: Vi4 MLP: Changing bundle bandwidth from 100000 to 10000

*Jan 14 11:01:14.897: Vi4 MLP: Ready to finish adding link Vi3 to bundle

*Jan 14 11:01:14.897: Vi3 MLP: Computed frag size 37492 exceeds MTU, changed to 1488

*Jan 14 11:01:14.897: Vi4 MLP: Update bundle bandwidth 10000 set 10000

*Jan 14 11:01:14.897: Vi3 MLP: Change transmit status from Init to Enabled, transmit links 1

*Jan 14 11:01:14.897: Vi4 MLP: Added first link Vi3 to bundle user@cisco.com

*Jan 14 11:01:14.898: Vi3 MLP: Updating bundle's PPP handle[0x5900000E] in SSS context

*Jan 14 11:01:14.898: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up

*Jan 14 11:01:14.898: Vi4 MLP: Received segment updated message for bundle

*Jan 14 11:01:14.915: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to up

*Jan 14 11:01:14.915: Vi4 PPP: Force LCP OPEN on MLP Bundle

*Jan 14 11:01:14.915: Vi3 PPP: Queue IPCP code[1] id[1]

*Jan 14 11:01:14.915: Vi4 PPP: Phase is UP

*Jan 14 11:01:14.915: Vi4 IPCP: Protocol configured, start CP. state[Initial]

*Jan 14 11:01:14.915: Vi4 IPCP: Event[OPEN] State[Initial to Starting]

*Jan 14 11:01:14.915: Vi4 IPCP: O CONFREQ [Starting] id 1 len 10

*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.10 (0x03060A0A0A0A)

*Jan 14 11:01:14.915: Vi4 IPCP: Event[UP] State[Starting to REQsent]

*Jan 14 11:01:14.915: Vi3 PPP: Process pending ncp packets

*Jan 14 11:01:14.915: Vi3 IPCP: Redirect packet to Vi4

*Jan 14 11:01:14.915: Vi4 IPCP: I CONFREQ [REQsent] id 1 len 10

*Jan 14 11:01:14.915: Vi4 IPCP:   Address 0.0.0.0 (0x030600000000)

*Jan 14 11:01:14.915: Vi4 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0

*Jan 14 11:01:14.915: Vi4 IPCP: Pool returned 10.10.10.18

*Jan 14 11:01:14.915: Vi4 IPCP: O CONFNAK [REQsent] id 1 len 10

*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)

*Jan 14 11:01:14.915: Vi4 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]

*Jan 14 11:01:14.915: Vi4 IPCP: I CONFACK [REQsent] id 1 len 10

*Jan 14 11:01:14.915: Vi4 IPCP:   Address 10.10.10.10 (0x03060A0A0A0A)

*Jan 14 11:01:14.915: Vi4 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]

*Jan 14 11:01:14.916: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to up

*Jan 14 11:01:14.936: Vi4 IPCP: I CONFREQ [ACKrcvd] id 2 len 10

*Jan 14 11:01:14.936: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)

*Jan 14 11:01:14.936: Vi4 IPCP: O CONFACK [ACKrcvd] id 2 len 10

*Jan 14 11:01:14.936: Vi4 IPCP:   Address 10.10.10.18 (0x03060A0A0A12)

*Jan 14 11:01:14.936: Vi4 IPCP: Event[Receive ConfReq+] State[ACKrcvd to Open]

*Jan 14 11:01:14.965: Vi4 IPCP: State is Open

*Jan 14 11:01:14.965: Vi4 Added to neighbor route AVL tree: topoid 0, address 10.10.10.18

*Jan 14 11:01:14.965: Vi4 IPCP: Install route to 10.10.10.18

LNS#show ppp all

Interface/ID OPEN+ Nego* Fail-     Stage   Peer Address   Peer Name

------------ --------------------- -------- --------------- --------------------

Vi4         IPCP+                 LocalT   10.10.10.18     user@cisco.com  

Vi3         LCP+ CHAP+           LocalT   10.10.10.18     user@cisco.com  

LNS#show ppp multilink

Virtual-Access4

Bundle name: user@cisco.com

Remote Username: user@cisco.com

Remote Endpoint Discriminator: [1] user@cisco.com

Local Username: LNS

Local Endpoint Discriminator: [1] user@cisco.com

Bundle up for 00:00:10, total bandwidth 10000, load 1/255

Receive buffer limit 12192 bytes, frag timeout 15 ms

Using relaxed lost fragment detection algorithm.

   0/0 fragments/bytes in reassembly list

   0 lost fragments, 0 reordered

   0/0 discarded fragments/bytes, 0 lost received

   0x0 received sequence, 0x3 sent sequence

Member links: 1 (max 255, min not set)

   LAC:Vi3 (192.168.1.1), since 00:00:10, 37500 weight, 1488 frag size, unsequenced

No inactive multilink interfaces

Related Information

• Configuring Client-Initiated Dial-In VPDN Tunneling
• Configuring Multilink PPP Connections for Broadband and Serial Topologies
• Technical Support & Documentation - Cisco Systems