Search This Blog

Sunday, August 31, 2014

PPPoE Configuration


This is an example for PPPoE configuration, client and server, with dynamic IP and PAP authentication.

PPPoE Server configuration:

interface Virtual-Template1
 ip address 10.0.0.3 255.255.255.0
 peer default ip address pool POOL1
 ppp authentication pap
!
bba-group pppoe GRP1
 virtual-template 1
!
interface FastEthernet1/0
 no ip address
 speed auto
 duplex auto
 pppoe enable group GRP1
!
ip local pool POOL1 10.0.0.10 10.0.0.15
!
username Cisco password Cisco

 

PPPoE Client configuration:

interface Dialer1
 mtu 1492
 ip address negotiated
 encapsulation ppp
 dialer pool 1
 ppp pap sent-username Cisco password Cisco
!
interface FastEthernet1/0
 no ip address
 speed auto
 duplex auto
 pppoe enable group global
 pppoe-client dial-pool-number 1

 
Server Log:

*Aug 31 19:45:56.207: Vi2.1 PPP: Missed 5 keepalives, taking LCP down
*Aug 31 19:45:56.207: Vi2.1 PPP DISC: Interface Shutdown by Admin
*Aug 31 19:45:56.211: PPP: NET STOP send to AAA.
*Aug 31 19:45:56.223: Vi2.1 IPCP: Event[DOWN] State[Open to Starting]
*Aug 31 19:45:56.227: Vi2.1 IPCP: Event[CLOSE] State[Starting to Initial]
*Aug 31 19:45:56.231: Vi2.1 LCP: O TERMREQ [Open] id 3 len 4
*Aug 31 19:45:56.235: Vi2.1 LCP: Event[CLOSE] State[Open to Closing]
*Aug 31 19:45:56.235: Vi2.1 PPP: Phase is TERMINATING
*Aug 31 19:45:56.243: Vi2.1 Deleted neighbor route from AVL tree: topoid 0, address 10.0.0.10
*Aug 31 19:45:56.247: Vi2.1 IPCP: Remove route to 10.0.0.10
*Aug 31 19:45:56.291: Vi2.1 LCP: Event[DOWN] State[Closing to Initial]
*Aug 31 19:45:56.295: Vi2.1 PPP: Phase is DOWN
*Aug 31 19:45:56.299: [3]PPPoE 3: State LOCALLY_TERMINATED    Event PPP DISCONNECT
*Aug 31 19:45:56.303: [3]PPPoE 3: Destroying  R:ca04.1e58.001c L:ca03.1e58.001c Fa1/0
*Aug 31 19:45:56.303: PPPoE: Returning Vaccess Virtual-Access2.1
*Aug 31 19:45:56.315: [3]PPPoE 3: AAA account stopped
*Aug 31 19:45:56.375: [3]PPPoE 3: Segment (SSS class): UNBOUND
*Aug 31 19:45:56.391: [3]PPPoE 3: Vi2.1 Block vaccess from being freed.
*Aug 31 19:45:56.399: [3]PPPoE 3: Segment (SSS class): UNPROVISION
*Aug 31 19:45:56.403: [3]PPPoE 3: failed to remove session from switching hash table.
*Aug 31 19:46:00.991: %SYS-5-CONFIG_I: Configured from console by console
*Aug 31 19:46:02.587: %LINK-3-UPDOWN: Interface FastEthernet1/0, changed state to up
*Aug 31 19:46:03.587: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet1/0, changed state to up
*Aug 31 19:46:06.875: PPPoE 0: I PADI  R:ca04.1e58.001c L:ffff.ffff.ffff Fa1/0
*Aug 31 19:46:06.879:  Service tag: NULL Tag
*Aug 31 19:46:06.883: PPPoE 0: O PADO, R:ca03.1e58.001c L:ca04.1e58.001c Fa1/0
*Aug 31 19:46:06.883:  Service tag: NULL Tag
*Aug 31 19:46:08.919: PPPoE 0: I PADR  R:ca04.1e58.001c L:ca03.1e58.001c Fa1/0
*Aug 31 19:46:08.923:  Service tag: NULL Tag
*Aug 31 19:46:08.923: PPPoE : encap string prepared
*Aug 31 19:46:08.927: [4]PPPoE 4: Access IE handle allocated
*Aug 31 19:46:08.927: [4]PPPoE 4: AAA unique ID F allocated
*Aug 31 19:46:08.931: [4]PPPoE 4: No AAA accounting method list
*Aug 31 19:46:08.931: [4]PPPoE 4: Service request sent to SSS
*Aug 31 19:46:08.935: [4]PPPoE 4: Created, Service: None R:ca03.1e58.001c L:ca04.1e58.001c Fa1/0
*Aug 31 19:46:08.967: [4]PPPoE 4: State NAS_PORT_POLICY_INQUIRY    Event SSS MORE KEYS
*Aug 31 19:46:08.967: PPP: Alloc Context [66B28F78]
*Aug 31 19:46:08.971: ppp4 PPP: Phase is ESTABLISHING
*Aug 31 19:46:08.979: [4]PPPoE 4: data path set to PPP
*Aug 31 19:46:08.983: [4]PPPoE 4: Segment (SSS class): PROVISION
*Aug 31 19:46:08.983: [4]PPPoE 4: State PROVISION_PPP    Event SSM PROVISIONED
*Aug 31 19:46:08.987: [4]PPPoE 4: O PADS  R:ca04.1e58.001c L:ca03.1e58.001c Fa1/0
*Aug 31 19:46:08.991: [4]PPPoE 4: Unable to Add ANCP Line attributes to the PPPoE Authen attributes
*Aug 31 19:46:08.995: ppp4 PPP: Using vpn set call direction
*Aug 31 19:46:08.999: ppp4 PPP: Treating connection as a callin
*Aug 31 19:46:08.999: ppp4 PPP: Session handle[BD000004] Session id[4]
*Aug 31 19:46:08.999: ppp4 LCP: Event[OPEN] State[Initial to Starting]
*Aug 31 19:46:09.003: ppp4 PPP LCP: Enter passive mode, state[Stopped]
*Aug 31 19:46:09.359: ppp4 LCP: I CONFREQ [Stopped] id 1 len 14
*Aug 31 19:46:09.363: ppp4 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:46:09.363: ppp4 LCP:    MagicNumber 0x042F016B (0x0506042F016B)
*Aug 31 19:46:09.367: ppp4 LCP: O CONFREQ [Stopped] id 1 len 18
*Aug 31 19:46:09.367: ppp4 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:46:09.367: ppp4 LCP:    AuthProto PAP (0x0304C023)
*Aug 31 19:46:09.371: ppp4 LCP:    MagicNumber 0x032F2E7A (0x0506032F2E7A)
*Aug 31 19:46:09.375: ppp4 LCP: O CONFACK [Stopped] id 1 len 14
*Aug 31 19:46:09.375: ppp4 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:46:09.379: ppp4 LCP:    MagicNumber 0x042F016B (0x0506042F016B)
*Aug 31 19:46:09.379: ppp4 LCP: Event[Receive ConfReq+] State[Stopped to ACKsent]
*Aug 31 19:46:09.427: ppp4 LCP: I CONFACK [ACKsent] id 1 len 18
*Aug 31 19:46:09.427: ppp4 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:46:09.431: ppp4 LCP:    AuthProto PAP (0x0304C023)
*Aug 31 19:46:09.431: ppp4 LCP:    MagicNumber 0x032F2E7A (0x0506032F2E7A)
*Aug 31 19:46:09.431: ppp4 LCP: Event[Receive ConfAck] State[ACKsent to Open]
*Aug 31 19:46:09.455: ppp4 PPP: Phase is AUTHENTICATING, by this end
*Aug 31 19:46:09.455: ppp4 LCP: State is Open
*Aug 31 19:46:09.487: ppp4 PAP: I AUTH-REQ id 1 len 16 from "Cisco"
*Aug 31 19:46:09.491: ppp4 PAP: Authenticating peer Cisco
*Aug 31 19:46:09.491: ppp4 PPP: Phase is FORWARDING, Attempting Forward
*Aug 31 19:46:09.511: ppp4 PPP: Phase is AUTHENTICATING, Unauthenticated User
*Aug 31 19:46:09.515: ppp4 PPP: Sent PAP LOGIN Request
*Aug 31 19:46:09.527: ppp4 PPP: Received LOGIN Response PASS
*Aug 31 19:46:09.531: ppp4 IPCP: Authorizing CP
*Aug 31 19:46:09.531: ppp4 IPCP: CP stalled on event[Authorize CP]
*Aug 31 19:46:09.543: ppp4 IPCP: CP unstall
*Aug 31 19:46:09.547: ppp4 PPP: Phase is FORWARDING, Attempting Forward
*Aug 31 19:46:09.695: [4]PPPoE 4: State LCP_NEGOTIATION    Event SSS CONNECT LOCAL
*Aug 31 19:46:09.739: [4]PPPoE 4: Segment (SSS class): UPDATED
*Aug 31 19:46:09.743: [4]PPPoE 4: Segment (SSS class): BOUND
*Aug 31 19:46:09.743: [4]PPPoE 4: data path set to Virtual Acess
*Aug 31 19:46:09.747: [4]PPPoE 4: State LCP_NEGOTIATION    Event SSM UPDATED
*Aug 31 19:46:09.751: Vi2.1 PPP: Phase is AUTHENTICATING, Authenticated User
*Aug 31 19:46:09.755: Vi2.1 PAP: O AUTH-ACK id 1 len 5
*Aug 31 19:46:09.759: Vi2.1 PPP: Phase is UP
*Aug 31 19:46:09.759: Vi2.1 IPCP: Protocol configured, start CP. state[Initial]
*Aug 31 19:46:09.763: Vi2.1 IPCP: Event[OPEN] State[Initial to Starting]
*Aug 31 19:46:09.767: Vi2.1 IPCP: O CONFREQ [Starting] id 1 len 10
*Aug 31 19:46:09.767: Vi2.1 IPCP:    Address 10.0.0.3 (0x03060A000003)
*Aug 31 19:46:09.767: Vi2.1 IPCP: Event[UP] State[Starting to REQsent]
*Aug 31 19:46:09.779: [4]PPPoE 4: State PTA_BINDING    Event STATIC BIND RESPONSE
*Aug 31 19:46:09.783: [4]PPPoE 4: Connected PTA
*Aug 31 19:46:10.459: Vi2.1 IPCP: I CONFREQ [REQsent] id 1 len 10
*Aug 31 19:46:10.463: Vi2.1 IPCP:    Address 0.0.0.0 (0x030600000000)
*Aug 31 19:46:10.467: Vi2.1 IPCP AUTHOR: Start.  Her address 0.0.0.0, we want 0.0.0.0
*Aug 31 19:46:10.467: Vi2.1 IPCP AUTHOR: Done.  Her address 0.0.0.0, we want 0.0.0.0
*Aug 31 19:46:10.471: Vi2.1 IPCP: Pool returned 10.0.0.11
*Aug 31 19:46:10.475: Vi2.1 IPCP: O CONFNAK [REQsent] id 1 len 10
*Aug 31 19:46:10.475: Vi2.1 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:10.479: Vi2.1 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]
*Aug 31 19:46:10.491: Vi2.1 CDPCP: I CONFREQ [UNKNOWN] id 1 len 4
*Aug 31 19:46:10.491: Vi2.1 LCP: O PROTREJ [Open] id 2 len 10 protocol CDPCP (0x01010004)
*Aug 31 19:46:10.495: Vi2.1 IPCP: I CONFACK [REQsent] id 1 len 10
*Aug 31 19:46:10.495: Vi2.1 IPCP:    Address 10.0.0.3 (0x03060A000003)
*Aug 31 19:46:10.499: Vi2.1 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Aug 31 19:46:10.595: Vi2.1 IPCP: I CONFREQ [ACKrcvd] id 2 len 10
*Aug 31 19:46:10.599: Vi2.1 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:10.599: Vi2.1 IPCP: O CONFACK [ACKrcvd] id 2 len 10
*Aug 31 19:46:10.603: Vi2.1 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:10.603: Vi2.1 IPCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Aug 31 19:46:10.607: Vi2.1 IPCP: State is Open
*Aug 31 19:46:10.619: PPPoE : ipfib_encapstr  prepared
*Aug 31 19:46:10.627: Vi2.1 Added to neighbor route AVL tree: topoid 0, address 10.0.0.11
*Aug 31 19:46:10.627: Vi2.1 IPCP: Install route to 10.0.0.11
 

Client Log:

*Aug 31 19:45:49.239: %LINK-3-UPDOWN: Interface FastEthernet1/0, changed state to up
*Aug 31 19:45:50.239: %LINEPROTO-5-UPDOWN: Line protocol on Interface FastEthernet1/0, changed state to up
*Aug 31 19:45:53.507: %SYS-5-CONFIG_I: Configured from console by console
*Aug 31 19:45:56.599:  Sending PADI: Interface = FastEthernet1/0
*Aug 31 19:45:56.655: PPPoE 0: I PADO  R:ca03.1e58.001c L:ca04.1e58.001c Fa1/0
*Aug 31 19:45:58.647:  PPPOE: we've got our pado and the pado timer went off
*Aug 31 19:45:58.647: OUT PADR from PPPoE Session
*Aug 31 19:45:58.799: PPPoE 4: I PADS  R:ca03.1e58.001c L:ca04.1e58.001c Fa1/0
*Aug 31 19:45:58.803: IN PADS from PPPoE Session
*Aug 31 19:45:58.827: %DIALER-6-BIND: Interface Vi2 bound to profile Di1
*Aug 31 19:45:58.831: PPPoE: Virtual Access interface obtained.
*Aug 31 19:45:58.835: PPPoE : encap string prepared
*Aug 31 19:45:58.835: [0]PPPoE 4: data path set to PPPoE Client
*Aug 31 19:45:58.847: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
*Aug 31 19:45:58.851: Vi2 PPP: Sending cstate UP notification
*Aug 31 19:45:58.855: Vi2 PPP: Processing CstateUp message
*Aug 31 19:45:58.895: PPP: Alloc Context [66B28F78]
*Aug 31 19:45:58.895: ppp4 PPP: Phase is ESTABLISHING
*Aug 31 19:45:58.899: Vi2 PPP: Using dialer call direction
*Aug 31 19:45:58.903: Vi2 PPP: Treating connection as a callout
*Aug 31 19:45:58.903: Vi2 PPP: Session handle[9D000004] Session id[4]
*Aug 31 19:45:58.907: Vi2 LCP: Event[OPEN] State[Initial to Starting]
*Aug 31 19:45:58.907: Vi2 PPP: No remote authentication for call-out
*Aug 31 19:45:58.911: Vi2 LCP: O CONFREQ [Starting] id 1 len 14
*Aug 31 19:45:58.911: Vi2 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:45:58.915: Vi2 LCP:    MagicNumber 0x042F016B (0x0506042F016B)
*Aug 31 19:45:58.915: Vi2 LCP: Event[UP] State[Starting to REQsent]
*Aug 31 19:45:58.951: Vi2 LCP: I CONFREQ [REQsent] id 1 len 18
*Aug 31 19:45:58.955: Vi2 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:45:58.955: Vi2 LCP:    AuthProto PAP (0x0304C023)
*Aug 31 19:45:58.959: Vi2 LCP:    MagicNumber 0x032F2E7A (0x0506032F2E7A)
*Aug 31 19:45:58.959: Vi2 LCP: O CONFACK [REQsent] id 1 len 18
*Aug 31 19:45:58.963: Vi2 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:45:58.963: Vi2 LCP:    AuthProto PAP (0x0304C023)
*Aug 31 19:45:58.967: Vi2 LCP:    MagicNumber 0x032F2E7A (0x0506032F2E7A)
*Aug 31 19:45:58.967: Vi2 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent]
*Aug 31 19:45:58.971: Vi2 LCP: I CONFACK [ACKsent] id 1 len 14
*Aug 31 19:45:58.971: Vi2 LCP:    MRU 1492 (0x010405D4)
*Aug 31 19:45:58.971: Vi2 LCP:    MagicNumber 0x042F016B (0x0506042F016B)
*Aug 31 19:45:58.975: Vi2 LCP: Event[Receive ConfAck] State[ACKsent to Open]
*Aug 31 19:45:58.991: Vi2 PPP: No authorization without authentication
*Aug 31 19:45:58.991: Vi2 PPP: Phase is AUTHENTICATING, by the peer
*Aug 31 19:45:58.995: Vi2 PAP: Using hostname from interface PAP
*Aug 31 19:45:58.995: Vi2 PAP: Using password from interface PAP
*Aug 31 19:45:58.999: Vi2 PAP: O AUTH-REQ id 1 len 16 from "Cisco"
*Aug 31 19:45:58.999: Vi2 LCP: State is Open
*Aug 31 19:45:59.971: Vi2 PAP: I AUTH-ACK id 1 len 5
*Aug 31 19:45:59.975: Vi2 PPP: Phase is FORWARDING, Attempting Forward
*Aug 31 19:45:59.975: Vi2 PPP: Queue IPCP code[1] id[1]
*Aug 31 19:46:00.011: Vi2 PPP: Phase is ESTABLISHING, Finish LCP
*Aug 31 19:46:00.015: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up
*Aug 31 19:46:00.031: Vi2 PPP: Phase is UP
*Aug 31 19:46:00.035: Vi2 IPCP: Protocol configured, start CP. state[Initial]
*Aug 31 19:46:00.035: Vi2 IPCP: Event[OPEN] State[Initial to Starting]
*Aug 31 19:46:00.039: Vi2 IPCP: O CONFREQ [Starting] id 1 len 10
*Aug 31 19:46:00.039: Vi2 IPCP:    Address 0.0.0.0 (0x030600000000)
*Aug 31 19:46:00.043: Vi2 IPCP: Event[UP] State[Starting to REQsent]
*Aug 31 19:46:00.047: Vi2 CDPCP: Protocol configured, start CP. state[Initial]
*Aug 31 19:46:00.047: Vi2 CDPCP: Event[OPEN] State[Initial to Starting]
*Aug 31 19:46:00.047: Vi2 CDPCP: O CONFREQ [Starting] id 1 len 4
*Aug 31 19:46:00.051: Vi2 CDPCP: Event[UP] State[Starting to REQsent]
*Aug 31 19:46:00.051: Vi2 PPP: Process pending ncp packets
*Aug 31 19:46:00.055: Vi2 IPCP: Redirect packet to Vi2
*Aug 31 19:46:00.055: Vi2 IPCP: I CONFREQ [REQsent] id 1 len 10
*Aug 31 19:46:00.059: Vi2 IPCP:    Address 10.0.0.3 (0x03060A000003)
*Aug 31 19:46:00.059: Vi2 IPCP: O CONFACK [REQsent] id 1 len 10
*Aug 31 19:46:00.063: Vi2 IPCP:    Address 10.0.0.3 (0x03060A000003)
*Aug 31 19:46:00.063: Vi2 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent]
*Aug 31 19:46:00.099: Vi2 IPCP: I CONFNAK [ACKsent] id 1 len 10
*Aug 31 19:46:00.103: Vi2 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:00.103: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10
*Aug 31 19:46:00.107: Vi2 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:00.107: Vi2 IPCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
*Aug 31 19:46:00.111: Vi2 LCP: I PROTREJ [Open] id 2 len 10 protocol CDPCP (0x01010004)
*Aug 31 19:46:00.111: Vi2 CDPCP: Event[Receive CodeRej-] State[REQsent to Stopped]
*Aug 31 19:46:00.115: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 10
*Aug 31 19:46:00.115: Vi2 IPCP:    Address 10.0.0.11 (0x03060A00000B)
*Aug 31 19:46:00.119: Vi2 IPCP: Event[Receive ConfAck] State[ACKsent to Open]
*Aug 31 19:46:00.131: Vi2 IPCP: State is Open
*Aug 31 19:46:00.131: Di1 IPCP: Install negotiated IP interface address 10.0.0.11
*Aug 31 19:46:00.183: PPPoE : ipfib_encapstr  prepared
*Aug 31 19:46:00.195: Di1 Added to neighbor route AVL tree: topoid 0, address 10.0.0.3
*Aug 31 19:46:00.195: Di1 IPCP: Install route to 10.0.0.3
*Aug 31 19:46:00.203: PPPoE : ipfib_encapstr  prepared