Serial Interfaces (HDLC/PPP)

Serial interfaces can have different types of encapsulations and each encapsulation type determines the kind of keepalives that will be used.
Enter the keepalive command in interface configuration mode in order to set the frequency at which a router sends ECHOREQ packets to its peer, keepalives can also be disabled with the “keepalive 0″ or “no keepalive”  commands.

Note: The keepalive command applies to serial interfaces that use High-Level Data Link Contol (HDLC) or PPP encapsulation. It does not apply to serial interfaces that use Frame Relay encapsulation. HDLC is the default encapsulation on Cisco serial links.

HDLC Keepalives

Another well-known keepalive mechanism is serial keepalives for HDLC. Serial keepalives are sent back and forth between two routers and the keepalives are acknowledged. With the use of sequence numbers to track each keepalive, each device is able to confirm if it’s HDLC peer received the keepalive it sent. For HDLC encapsulation, three ignored keepalives causes the interface to be brought down.

Since HDLC keepalives are ECHOREQ type keepalives, the keepalive frequency is important and it is recommended that they match up exactly on both sides.
If the timers are out of sync, the sequence numbers start to get out of order. For example, if you set one side to 10 seconds and the other to 25 seconds, it will still allow the interface to remain up as long as the difference in frequency is not sufficient to cause the sequence numbers to be off by a difference of three.

HDLC keepalives contain three pieces in order to determine it works:

  • The “myseq” which is our own incrementing number.
  • The “mineseen” which is actually an acknowledgement from the other side (incremented) which says they expect this number from us.
  • The “yourseen” which is our acknowledgement to the other side.

The messages can be seen with the debug serial interface command.

*May 27 09:31:19.945: %LINK-3-UPDOWN: Interface Serial1/0, changed state to up
*May 27 09:31:20.954: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to up
*May 27 09:31:32.519: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.2 (Serial1/0) is up: new adjacency
*May 27 09:31:39.343: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:31:49.387: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:31:49.951: Serial1/0: HDLC myseq 1, mineseen 1*, yourseen 349, line up
*May 27 09:31:59.345: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 9
*May 27 09:32:01.895: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.2 (Serial1/0) is down: holding time expired
*May 27 09:32:03.658: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.2 (Serial1/0) is up: new adjacency
*May 27 09:32:09.355: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:32:14.952: Serial1/0: HDLC myseq 2, mineseen 2*, yourseen 351, line up
*May 27 09:32:19.358: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:32:29.363: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:32:39.365: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:32:39.960: Serial1/0: HDLC myseq 3, mineseen 3*, yourseen 354, line up
*May 27 09:32:49.368: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:32:59.375: Serial1/0 – Keepalive time mismatch – should be 25 secs, is 10
*May 27 09:33:04.966: Serial1/0: HDLC myseq 4, mineseen 4*, yourseen 356, line up

If you set the keepalive very high then EIGRP might not come up again for a while. If “no keepalive” is set then EIGRP does not come-up all and you see the following output in the debug messages.

*May 27 09:45:29.758: Serial1/0 – Got keepalive with none configured

PPP Keepalives

PPP keepalives are a little bit different from HDLC keepalives. Unlike HDLC, PPP keepalives are more like pings. Both sides can ping each other at their leisure. The proper negotiated move is to ALWAYS respond to this “ping”. So for PPP keepalives, the frequency or the timer value are only locally relevant and have no impact on the other side. Even if one side turns the keepalives off, it will still RESPOND to those echo requests from the side that does have a keepalive timer. However, it will never initiate any of its own.

The messages can be seen with the debug ppp packet command.

PPP keepalives contain three pieces:

  • ID number – used to identify which ECHOREQ the peer responds to.
  • Keepalive type – ECHOREQ are keepalives sent by the originating device and ECHOREP are responses sent by the peer.
  • Magic numbers – the notifications include the magic numbers of both the server and the remote client. The peer validates the magic number in the LCP Echo-Request packet, and transmits the corresponding LCP Echo-Reply packet that contains the magic number negotiated by the router.

For PPP encapsulation, five ignored keepalives causes the interface to be brought down

PAP Authentication

Bi-directional PAP Example below.

# CLIENT

username NAS password 0 cisco123

interface Serial1/0
ip address 10.0.0.1 255.255.255.0
encapsulation ppp
ppp authentication pap
ppp pap sent-username CLIENT-1 password 0 cisco123

PPP authentication debugging is on
PPP protocol negotiation debugging is on
R1(config-if)#no shut
*May 28 13:39:48.034: %LINK-3-UPDOWN: Interface Serial1/0, changed state to up
*May 28 13:39:48.034: Se1/0 PPP: Sending cstate UP notification
*May 28 13:39:48.035: Se1/0 PPP: Processing CstateUp message
*May 28 13:39:48.035: PPP: Alloc Context [C2B18F8C] *May 28 13:39:48.035: ppp447 PPP: Phase is ESTABLISHING
*May 28 13:39:48.035: Se1/0 PPP: Using default call direction
*May 28 13:39:48.036: Se1/0 PPP: Treating connection as a dedicated line
*May 28 13:39:48.036: Se1/0 PPP: Session handle[730005AA] Session id[447] *May 28 13:39:48.036: Se1/0 LCP: Event[OPEN] State[Initial to Starting] *May 28 13:39:48.036: Se1/0 LCP: O CONFREQ [Starting] id 1 len 14
*May 28 13:39:48.036: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:39:48.036: Se1/0 LCP: MagicNumber 0xBC33F68B (0x0506BC33F68B)
*May 28 13:39:48.036: Se1/0 LCP: Event[UP] State[Starting to REQsent] *May 28 13:39:48.045: Se1/0 LCP: I CONFREQ [REQsent] id 1 len 14
*May 28 13:39:48.045: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:39:48.045: Se1/0 LCP: MagicNumber 0xBC33FDB2 (0x0506BC33FDB2)
*May 28 13:39:48.045: Se1/0 LCP: O CONFACK [REQsent] id 1 len 14
*May 28 13:39:48.045: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:39:48.045: Se1/0 LCP: MagicNumber 0xBC33FDB2 (0x0506BC33FDB2)
*May 28 13:39:48.045: Se1/0 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:39:48.045: Se1/0 LCP: I CONFACK [ACKsent] id 1 len 14
*May 28 13:39:48.045: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:39:48.045: Se1/0 LCP: MagicNumber 0xBC33F68B (0x0506BC33F68B)
*May 28 13:39:48.045: Se1/0 LCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:39:48.064: Se1/0 PPP: Phase is AUTHENTICATING, by both
*May 28 13:39:48.064: Se1/0 PAP: Using hostname from interface PAP
*May 28 13:39:48.064: Se1/0 PAP: Using password from interface PAP
*May 28 13:39:48.064: Se1/0 PAP: O AUTH-REQ id 1 len 22 from “CLIENT-1”
*May 28 13:39:48.064: Se1/0 LCP: State is Open
*May 28 13:39:48.069: Se1/0 PAP: I AUTH-REQ id 1 len 17 from “NAS”
*May 28 13:39:48.069: Se1/0 PAP: Authenticating peer NAS
*May 28 13:39:48.070: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 13:39:48.070: Se1/0 PPP: Phase is AUTHENTICATING, Unauthenticated User
*May 28 13:39:48.070: Se1/0 PPP: Sent PAP LOGIN Request
*May 28 13:39:48.070: Se1/0 PPP: Received LOGIN Response PASS
*May 28 13:39:48.070: Se1/0 IPCP: Authorizing CP
*May 28 13:39:48.070: Se1/0 IPCP: CP stalled on event[Authorize CP] *May 28 13:39:48.070: Se1/0 IPCP: CP unstall
*May 28 13:39:48.070: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 13:39:48.076: Se1/0 PPP: Phase is AUTHENTICATING, Authenticated User
*May 28 13:39:48.076: Se1/0 PAP: O AUTH-ACK id 1 len 5
*May 28 13:39:48.076: Se1/0 PAP: I AUTH-ACK id 1 len 5
*May 28 13:39:48.076: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to up
*May 28 13:39:48.077: Se1/0 PPP: Phase is UP
*May 28 13:39:48.077: Se1/0 IPCP: Protocol configured, start CP. state[Initial] *May 28 13:39:48.077: Se1/0 IPCP: Event[OPEN] State[Initial to Starting] *May 28 13:39:48.077: Se1/0 IPCP: O CONFREQ [Starting] id 1 len 10
*May 28 13:39:48.077: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 13:39:48.077: Se1/0 IPCP: Event[UP] State[Starting to REQsent] *May 28 13:39:48.077: Se1/0 CDPCP: Protocol configured, start CP. state[Initial] *May 28 13:39:48.077: Se1/0 CDPCP: Event[OPEN] State[Initial to Starting] *May 28 13:39:48.077: Se1/0 CDPCP: Authorizing CP
*May 28 13:39:48.077: Se1/0 CDPCP: CP stalled on event[Authorize CP] *May 28 13:39:48.078: Se1/0 CDPCP: CP unstall
*May 28 13:39:48.078: Se1/0 CDPCP: O CONFREQ [Starting] id 1 len 4
*May 28 13:39:48.078: Se1/0 CDPCP: Event[UP] State[Starting to REQsent] *May 28 13:39:48.079: Se1/0 IPCP: I CONFREQ [REQsent] id 1 len 10
*May 28 13:39:48.079: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 13:39:48.079: Se1/0 IPCP AUTHOR: Start. Her address 10.0.0.2, we want 0.0.0.0
*May 28 13:39:48.079: Se1/0 IPCP AUTHOR: Reject 10.0.0.2, using 0.0.0.0
*May 28 13:39:48.079: Se1/0 IPCP AUTHOR: Done. Her address 10.0.0.2, we want 0.0.0.0
*May 28 13:39:48.079: Se1/0 IPCP: O CONFACK [REQsent] id 1 len 10
*May 28 13:39:48.079: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 13:39:48.079: Se1/0 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:39:48.085: Se1/0 IPCP: I CONFACK [ACKsent] id 1 len 10
*May 28 13:39:48.085: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 13:39:48.085: Se1/0 IPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:39:48.085: Se1/0 CDPCP: I CONFREQ [REQsent] id 1 len 4
*May 28 13:39:48.085: Se1/0 CDPCP: O CONFACK [REQsent] id 1 len 4
*May 28 13:39:48.085: Se1/0 CDPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:39:48.085: Se1/0 CDPCP: I CONFACK [ACKsent] id 1 len 4
*May 28 13:39:48.085: Se1/0 CDPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:39:48.099: Se1/0 IPCP: State is Open
*May 28 13:39:48.099: Se1/0 CDPCP: State is Open
*May 28 13:39:48.100: Se1/0 Added to neighbor route AVL tree: topoid 0, address 10.0.0.2
*May 28 13:39:48.100: Se1/0 IPCP: Install route to 10.0.0.2
*May 28 13:39:49.086: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.2 (Serial1/0) is up: new adjacency

sh ppp all
Interface/ID OPEN+ Nego* Fail- Stage Peer Address Peer Name
———— ——————— ——– ————— ——————–
Se1/0 LCP+ PAP+ IPCP+ CDPC> LocalT 10.0.0.2 NAS

# NAS

username CLIENT-1 password 0 cisco123

interface Serial1/0
ip address 10.0.0.2 255.255.255.0
encapsulation ppp
ppp authentication pap
ppp pap sent-username NAS password 0 cisco123

*May 28 13:44:01.180: %LINK-3-UPDOWN: Interface Serial1/0, changed state to up
*May 28 13:44:01.180: Se1/0 PPP: Sending cstate UP notification
*May 28 13:44:01.180: Se1/0 PPP: Processing CstateUp message
*May 28 13:44:01.181: PPP: Alloc Context [C2B0B038] *May 28 13:44:01.181: ppp444 PPP: Phase is ESTABLISHING
*May 28 13:44:01.181: Se1/0 PPP: Using default call direction
*May 28 13:44:01.181: Se1/0 PPP: Treating connection as a dedicated line
*May 28 13:44:01.181: Se1/0 PPP: Session handle[D70005A9] Session id[444] *May 28 13:44:01.181: Se1/0 LCP: Event[OPEN] State[Initial to Starting] *May 28 13:44:01.181: Se1/0 LCP: O CONFREQ [Starting] id 1 len 14
*May 28 13:44:01.181: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:44:01.181: Se1/0 LCP: MagicNumber 0xBC37DB3E (0x0506BC37DB3E)
*May 28 13:44:01.181: Se1/0 LCP: Event[UP] State[Starting to REQsent] *May 28 13:44:01.191: Se1/0 LCP: I CONFREQ [REQsent] id 1 len 14
*May 28 13:44:01.191: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:44:01.191: Se1/0 LCP: MagicNumber 0xBC37D407 (0x0506BC37D407)
*May 28 13:44:01.191: Se1/0 LCP: O CONFACK [REQsent] id 1 len 14
*May 28 13:44:01.191: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:44:01.191: Se1/0 LCP: MagicNumber 0xBC37D407 (0x0506BC37D407)
*May 28 13:44:01.191: Se1/0 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:44:01.191: Se1/0 LCP: I CONFACK [ACKsent] id 1 len 14
*May 28 13:44:01.191: Se1/0 LCP: AuthProto PAP (0x0304C023)
*May 28 13:44:01.191: Se1/0 LCP: MagicNumber 0xBC37DB3E (0x0506BC37DB3E)
*May 28 13:44:01.191: Se1/0 LCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:44:01.215: Se1/0 PPP: Phase is AUTHENTICATING, by both
*May 28 13:44:01.215: Se1/0 PAP: Using hostname from interface PAP
*May 28 13:44:01.215: Se1/0 PAP: Using password from interface PAP
*May 28 13:44:01.215: Se1/0 PAP: O AUTH-REQ id 1 len 17 from “NAS”
*May 28 13:44:01.215: Se1/0 LCP: State is Open
*May 28 13:44:01.216: Se1/0 PAP: I AUTH-REQ id 1 len 22 from “CLIENT-1”
*May 28 13:44:01.217: Se1/0 PAP: Authenticating peer CLIENT-1
*May 28 13:44:01.217: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 13:44:01.217: Se1/0 PPP: Phase is AUTHENTICATING, Unauthenticated User
*May 28 13:44:01.217: Se1/0 PPP: Sent PAP LOGIN Request
*May 28 13:44:01.217: Se1/0 PPP: Received LOGIN Response PASS
*May 28 13:44:01.217: Se1/0 IPCP: Authorizing CP
*May 28 13:44:01.217: Se1/0 IPCP: CP stalled on event[Authorize CP] *May 28 13:44:01.217: Se1/0 IPCP: CP unstall
*May 28 13:44:01.217: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 13:44:01.223: Se1/0 PPP: Phase is AUTHENTICATING, Authenticated User
*May 28 13:44:01.223: Se1/0 PAP: O AUTH-ACK id 1 len 5
*May 28 13:44:01.224: Se1/0 PAP: I AUTH-ACK id 1 len 5
*May 28 13:44:01.224: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to up
*May 28 13:44:01.224: Se1/0 PPP: Phase is UP
*May 28 13:44:01.224: Se1/0 IPCP: Protocol configured, start CP. state[Initial] *May 28 13:44:01.224: Se1/0 IPCP: Event[OPEN] State[Initial to Starting] *May 28 13:44:01.224: Se1/0 IPCP: O CONFREQ [Starting] id 1 len 10
*May 28 13:44:01.224: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 13:44:01.224: Se1/0 IPCP: Event[UP] State[Starting to REQsent] *May 28 13:44:01.224: Se1/0 CDPCP: Protocol configured, start CP. state[Initial] *May 28 13:44:01.224: Se1/0 CDPCP: Event[OPEN] State[Initial to Starting] *May 28 13:44:01.224: Se1/0 CDPCP: Authorizing CP
*May 28 13:44:01.224: Se1/0 CDPCP: CP stalled on event[Authorize CP] *May 28 13:44:01.226: Se1/0 IPCP: I CONFREQ [REQsent] id 1 len 10
*May 28 13:44:01.226: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 13:44:01.226: Se1/0 IPCP AUTHOR: Start. Her address 10.0.0.1, we want 0.0.0.0
*May 28 13:44:01.226: Se1/0 IPCP AUTHOR: Reject 10.0.0.1, using 0.0.0.0
*May 28 13:44:01.226: Se1/0 IPCP AUTHOR: Done. Her address 10.0.0.1, we want 0.0.0.0
*May 28 13:44:01.226: Se1/0 IPCP: O CONFACK [REQsent] id 1 len 10
*May 28 13:44:01.226: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 13:44:01.226: Se1/0 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:44:01.226: Se1/0 CDPCP: I CONFREQ [Starting] id 1 len 4
*May 28 13:44:01.226: Se1/0 CDPCP: Store stalled packet [0xC4B58D10] *May 28 13:44:01.226: Se1/0 IPCP: I CONFACK [ACKsent] id 1 len 10
*May 28 13:44:01.226: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 13:44:01.226: Se1/0 IPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:44:01.226: Se1/0 CDPCP: CP unstall
*May 28 13:44:01.227: Se1/0 CDPCP: O CONFREQ [Starting] id 1 len 4
*May 28 13:44:01.227: Se1/0 CDPCP: Event[UP] State[Starting to REQsent] *May 28 13:44:01.227: Se1/0 CDPCP: Continue processing stalled packet:
*May 28 13:44:01.227: Se1/0 CDPCP: I CONFREQ [REQsent] id 1 len 4
*May 28 13:44:01.227: Se1/0 CDPCP: O CONFACK [REQsent] id 1 len 4
*May 28 13:44:01.227: Se1/0 CDPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 13:44:01.233: Se1/0 CDPCP: I CONFACK [ACKsent] id 1 len 4
*May 28 13:44:01.233: Se1/0 CDPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 13:44:01.250: Se1/0 IPCP: State is Open
*May 28 13:44:01.250: Se1/0 CDPCP: State is Open
*May 28 13:44:01.253: Se1/0 Added to neighbor route AVL tree: topoid 0, address 10.0.0.1
*May 28 13:44:01.253: Se1/0 IPCP: Install route to 10.0.0.1
*May 28 13:44:03.162: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.1 (Serial1/0) is up: new adjacency

sh ppp all
Interface/ID OPEN+ Nego* Fail- Stage Peer Address Peer Name
———— ——————— ——– ————— ——————–
Se1/0 LCP+ PAP+ IPCP+ CDPC> LocalT 10.0.0.1 CLIENT-1

CHAP Authentication

Chap works differently and does not send the password in clear text. It looks up the username in the local database or gets the info from a aaa server, normally this is the hostname of the router but can be changed with the  ppp chap hostname <x> interface command. The router performs a MD5 hash calculation on the local password and sends the hash value to it’s peer.

The example below shows  R1 performing the steps, the same process will apply to R2 when both sites are configured to authenticate each other.

Basic Bi-directional CHAP Example:

Rx(config)#int S1/0
Rx(config-if)# encapsulation ppp
Rx(config-if)# ppp authentication chap

R1(config)# username R2 password cisco
R2(config)# username R1 password cisco

Other PPP related commands

interface Serial1/0
ip address 10.0.0.1 255.255.255.0
encapsulation ppp
no peer neighbor-route  #Will not inject the peer route into local RIB
ppp authentication chap
ppp ipcp route default #Inject default route via peer next-hop

If both of these commands are configured as in the example above then neither the default or peer ip address will be injected into the local RIB.

#R1
*May 28 16:14:57.038: %LINK-3-UPDOWN: Interface Serial1/0, changed state to up
*May 28 16:14:57.039: Se1/0 PPP: Sending cstate UP notification
*May 28 16:14:57.039: Se1/0 PPP: Processing CstateUp message
*May 28 16:14:57.039: PPP: Alloc Context [C2B18F8C] *May 28 16:14:57.039: ppp570 PPP: Phase is ESTABLISHING
*May 28 16:14:57.039: Se1/0 PPP: Using default call direction
*May 28 16:14:57.039: Se1/0 PPP: Treating connection as a dedicated line
*May 28 16:14:57.039: Se1/0 PPP: Session handle[70000A11] Session id[570] *May 28 16:14:57.040: Se1/0 LCP: Event[OPEN] State[Initial to Starting] *May 28 16:14:57.040: Se1/0 LCP: O CONFREQ [Starting] id 1 len 15
*May 28 16:14:57.040: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:14:57.040: Se1/0 LCP: MagicNumber 0xBCC22376 (0x0506BCC22376)
*May 28 16:14:57.040: Se1/0 LCP: Event[UP] State[Starting to REQsent] *May 28 16:14:57.049: Se1/0 LCP: I CONFREQ [REQsent] id 1 len 15
*May 28 16:14:57.049: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:14:57.049: Se1/0 LCP: MagicNumber 0xBCC22E41 (0x0506BCC22E41)
*May 28 16:14:57.049: Se1/0 LCP: O CONFACK [REQsent] id 1 len 15
*May 28 16:14:57.049: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:14:57.049: Se1/0 LCP: MagicNumber 0xBCC22E41 (0x0506BCC22E41)
*May 28 16:14:57.049: Se1/0 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:14:57.049: Se1/0 LCP: I CONFACK [ACKsent] id 1 len 15
*May 28 16:14:57.049: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:14:57.049: Se1/0 LCP: MagicNumber 0xBCC22376 (0x0506BCC22376)
*May 28 16:14:57.049: Se1/0 LCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:14:57.054: Se1/0 PPP: Phase is AUTHENTICATING, by both
*May 28 16:14:57.054: Se1/0 CHAP: O CHALLENGE id 1 len 23 from “R1”
*May 28 16:14:57.054: Se1/0 LCP: State is Open
*May 28 16:14:57.055: Se1/0 CHAP: I CHALLENGE id 1 len 23 from “R2”
*May 28 16:14:57.055: Se1/0 PPP: Sent CHAP SENDAUTH Request
*May 28 16:14:57.055: Se1/0 PPP: Received SENDAUTH Response PASS
*May 28 16:14:57.055: Se1/0 CHAP: Using hostname from configured hostname
*May 28 16:14:57.055: Se1/0 CHAP: Using password from AAA
*May 28 16:14:57.055: Se1/0 CHAP: O RESPONSE id 1 len 23 from “R1”
*May 28 16:14:57.061: Se1/0 CHAP: I RESPONSE id 1 len 23 from “R2”
*May 28 16:14:57.061: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 16:14:57.061: Se1/0 PPP: Phase is AUTHENTICATING, Unauthenticated User
*May 28 16:14:57.061: Se1/0 PPP: Sent CHAP LOGIN Request
*May 28 16:14:57.061: Se1/0 PPP: Received LOGIN Response PASS
*May 28 16:14:57.061: Se1/0 IPCP: Authorizing CP
*May 28 16:14:57.062: Se1/0 IPCP: CP stalled on event[Authorize CP] *May 28 16:14:57.062: Se1/0 IPCP: CP unstall
*May 28 16:14:57.062: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 16:14:57.067: Se1/0 PPP: Phase is AUTHENTICATING, Authenticated User
*May 28 16:14:57.067: Se1/0 CHAP: O SUCCESS id 1 len 4
*May 28 16:14:57.068: Se1/0 CHAP: I SUCCESS id 1 len 4
*May 28 16:14:57.068: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to up
*May 28 16:14:57.068: Se1/0 PPP: Phase is UP
*May 28 16:14:57.069: Se1/0 IPCP: Protocol configured, start CP. state[Initial] *May 28 16:14:57.069: Se1/0 IPCP: Event[OPEN] State[Initial to Starting] *May 28 16:14:57.069: Se1/0 IPCP: O CONFREQ [Starting] id 1 len 10
*May 28 16:14:57.069: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 16:14:57.069: Se1/0 IPCP: Event[UP] State[Starting to REQsent] *May 28 16:14:57.069: Se1/0 CDPCP: Protocol configured, start CP. state[Initial] *May 28 16:14:57.069: Se1/0 CDPCP: Event[OPEN] State[Initial to Starting] *May 28 16:14:57.069: Se1/0 CDPCP: Authorizing CP
*May 28 16:14:57.069: Se1/0 CDPCP: CP stalled on event[Authorize CP] *May 28 16:14:57.070: Se1/0 IPCP: I CONFREQ [REQsent] id 1 len 10
*May 28 16:14:57.070: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 16:14:57.070: Se1/0 IPCP AUTHOR: Start. Her address 10.0.0.2, we want 0.0.0.0
*May 28 16:14:57.070: Se1/0 IPCP AUTHOR: Reject 10.0.0.2, using 0.0.0.0
*May 28 16:14:57.070: Se1/0 IPCP AUTHOR: Done. Her address 10.0.0.2, we want 0.0.0.0
*May 28 16:14:57.070: Se1/0 IPCP: O CONFACK [REQsent] id 1 len 10
*May 28 16:14:57.070: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 16:14:57.070: Se1/0 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:14:57.070: Se1/0 IPCP: I CONFACK [ACKsent] id 1 len 10
*May 28 16:14:57.070: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 16:14:57.070: Se1/0 IPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:14:57.070: Se1/0 CDPCP: CP unstall
*May 28 16:14:57.070: Se1/0 CDPCP: O CONFREQ [Starting] id 1 len 4
*May 28 16:14:57.070: Se1/0 CDPCP: Event[UP] State[Starting to REQsent] *May 28 16:14:57.071: Se1/0 CDPCP: I CONFREQ [REQsent] id 1 len 4
*May 28 16:14:57.071: Se1/0 CDPCP: O CONFACK [REQsent] id 1 len 4
*May 28 16:14:57.071: Se1/0 CDPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:14:57.071: Se1/0 CDPCP: I CONFACK [ACKsent] id 1 len 4
*May 28 16:14:57.071: Se1/0 CDPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:14:57.085: Se1/0 IPCP: State is Open
*May 28 16:14:57.085: Se1/0 CDPCP: State is Open
*May 28 16:14:58.462: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.2 (Serial1/0) is up: new adjacency

R1# sh ppp all
Interface/ID OPEN+ Nego* Fail- Stage Peer Address Peer Name
———— ——————— ——– ————— ——————–
Se1/0 LCP+ CHAP+ IPCP+ CDP> LocalT 10.0.0.2 R2

#R2
*May 28 16:18:06.092: Se1/0 LCP: I CONFREQ [Open] id 1 len 15
*May 28 16:18:06.092: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:18:06.092: Se1/0 LCP: MagicNumber 0xBCC50665 (0x0506BCC50665)
*May 28 16:18:06.092: Se1/0 PPP DISC: PPP Renegotiating
*May 28 16:18:06.092: PPP: NET STOP send to AAA.
*May 28 16:18:06.092: Se1/0 LCP: Event[LCP Reneg] State[Open to Open] *May 28 16:18:06.093: Se1/0 IPCP: Event[DOWN] State[Open to Starting] *May 28 16:18:06.093: Se1/0 IPCP: Event[CLOSE] State[Starting to Initial] *May 28 16:18:06.093: Se1/0 CDPCP: Event[DOWN] State[Open to Starting] *May 28 16:18:06.093: Se1/0 CDPCP: Event[CLOSE] State[Starting to Initial] *May 28 16:18:06.093: Se1/0 LCP: Event[DOWN] State[Open to Starting] *May 28 16:18:06.093: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to down
*May 28 16:18:06.093: Se1/0 PPP: Outbound cdp packet dropped, NCP not negotiated
*May 28 16:18:06.094: Se1/0 PPP: Phase is DOWN
*May 28 16:18:06.094: Se1/0 Deleted neighbor route from AVL tree: topoid 0, address 10.0.0.1
*May 28 16:18:06.094: Se1/0 IPCP: Remove route to 10.0.0.1
*May 28 16:18:06.096: PPP: Alloc Context [C2B0B038] *May 28 16:18:06.096: ppp563 PPP: Phase is ESTABLISHING
*May 28 16:18:06.096: Se1/0 PPP: Using default call direction
*May 28 16:18:06.096: Se1/0 PPP: Treating connection as a dedicated line
*May 28 16:18:06.096: Se1/0 PPP: Session handle[9D000A11] Session id[563] *May 28 16:18:06.096: Se1/0 LCP: Event[OPEN] State[Initial to Starting] *May 28 16:18:06.096: Se1/0 LCP: O CONFREQ [Starting] id 1 len 15
*May 28 16:18:06.096: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:18:06.096: Se1/0 LCP: MagicNumber 0xBCC51149 (0x0506BCC51149)
*May 28 16:18:06.096: Se1/0 LCP: Event[UP] State[Starting to REQsent] *May 28 16:18:06.096: Se1/0 LCP: I CONFREQ [REQsent] id 1 len 15
*May 28 16:18:06.096: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:18:06.096: Se1/0 LCP: MagicNumber 0xBCC50665 (0x0506BCC50665)
*May 28 16:18:06.096: Se1/0 LCP: O CONFACK [REQsent] id 1 len 15
*May 28 16:18:06.096: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:18:06.096: Se1/0 LCP: MagicNumber 0xBCC50665 (0x0506BCC50665)
*May 28 16:18:06.096: Se1/0 LCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:18:06.097: Se1/0 LCP: I CONFACK [ACKsent] id 1 len 15
*May 28 16:18:06.097: Se1/0 LCP: AuthProto CHAP (0x0305C22305)
*May 28 16:18:06.097: Se1/0 LCP: MagicNumber 0xBCC51149 (0x0506BCC51149)
*May 28 16:18:06.097: Se1/0 LCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:18:06.107: Se1/0 PPP: Phase is AUTHENTICATING, by both
*May 28 16:18:06.107: Se1/0 CHAP: O CHALLENGE id 1 len 23 from “R2”
*May 28 16:18:06.107: Se1/0 LCP: State is Open
*May 28 16:18:06.113: Se1/0 CHAP: I CHALLENGE id 1 len 23 from “R1”
*May 28 16:18:06.113: Se1/0 PPP: Sent CHAP SENDAUTH Request
*May 28 16:18:06.113: Se1/0 PPP: Received SENDAUTH Response PASS
*May 28 16:18:06.113: Se1/0 CHAP: Using hostname from configured hostname
*May 28 16:18:06.113: Se1/0 CHAP: Using password from AAA
*May 28 16:18:06.113: Se1/0 CHAP: O RESPONSE id 1 len 23 from “R2”
*May 28 16:18:06.118: Se1/0 CHAP: I RESPONSE id 1 len 23 from “R1”
*May 28 16:18:06.118: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 16:18:06.119: Se1/0 PPP: Phase is AUTHENTICATING, Unauthenticated User
*May 28 16:18:06.119: Se1/0 PPP: Sent CHAP LOGIN Request
*May 28 16:18:06.119: Se1/0 PPP: Received LOGIN Response PASS
*May 28 16:18:06.119: Se1/0 IPCP: Authorizing CP
*May 28 16:18:06.119: Se1/0 IPCP: CP stalled on event[Authorize CP] *May 28 16:18:06.119: Se1/0 IPCP: CP unstall
*May 28 16:18:06.119: Se1/0 PPP: Phase is FORWARDING, Attempting Forward
*May 28 16:18:06.124: Se1/0 PPP: Phase is AUTHENTICATING, Authenticated User
*May 28 16:18:06.124: Se1/0 CHAP: O SUCCESS id 1 len 4
*May 28 16:18:06.125: Se1/0 CHAP: I SUCCESS id 1 len 4
*May 28 16:18:06.125: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0, changed state to up
*May 28 16:18:06.126: Se1/0 PPP: Outbound cdp packet dropped, line protocol not up
*May 28 16:18:06.126: Se1/0 PPP: Phase is UP
*May 28 16:18:06.126: Se1/0 IPCP: Protocol configured, start CP. state[Initial] *May 28 16:18:06.126: Se1/0 IPCP: Event[OPEN] State[Initial to Starting] *May 28 16:18:06.126: Se1/0 IPCP: O CONFREQ [Starting] id 1 len 10
*May 28 16:18:06.126: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 16:18:06.126: Se1/0 IPCP: Event[UP] State[Starting to REQsent] *May 28 16:18:06.126: Se1/0 CDPCP: Protocol configured, start CP. state[Initial] *May 28 16:18:06.126: Se1/0 CDPCP: Event[OPEN] State[Initial to Starting] *May 28 16:18:06.126: Se1/0 CDPCP: Authorizing CP
*May 28 16:18:06.126: Se1/0 CDPCP: CP stalled on event[Authorize CP] *May 28 16:18:06.128: Se1/0 IPCP: I CONFREQ [REQsent] id 1 len 10
*May 28 16:18:06.128: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 16:18:06.128: Se1/0 IPCP AUTHOR: Start. Her address 10.0.0.1, we want 0.0.0.0
*May 28 16:18:06.128: Se1/0 IPCP AUTHOR: Reject 10.0.0.1, using 0.0.0.0
*May 28 16:18:06.128: Se1/0 IPCP AUTHOR: Done. Her address 10.0.0.1, we want 0.0.0.0
*May 28 16:18:06.128: Se1/0 IPCP: O CONFACK [REQsent] id 1 len 10
*May 28 16:18:06.128: Se1/0 IPCP: Address 10.0.0.1 (0x03060A000001)
*May 28 16:18:06.128: Se1/0 IPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:18:06.128: Se1/0 CDPCP: I CONFREQ [Starting] id 1 len 4
*May 28 16:18:06.128: Se1/0 CDPCP: Store stalled packet [0xC4B58CE4] *May 28 16:18:06.129: Se1/0 CDPCP: CP unstall
*May 28 16:18:06.129: Se1/0 CDPCP: O CONFREQ [Starting] id 1 len 4
*May 28 16:18:06.129: Se1/0 CDPCP: Event[UP] State[Starting to REQsent] *May 28 16:18:06.129: Se1/0 CDPCP: Continue processing stalled packet:
*May 28 16:18:06.129: Se1/0 CDPCP: I CONFREQ [REQsent] id 1 len 4
*May 28 16:18:06.129: Se1/0 CDPCP: O CONFACK [REQsent] id 1 len 4
*May 28 16:18:06.129: Se1/0 CDPCP: Event[Receive ConfReq+] State[REQsent to ACKsent] *May 28 16:18:06.130: Se1/0 IPCP: I CONFACK [ACKsent] id 1 len 10
*May 28 16:18:06.131: Se1/0 IPCP: Address 10.0.0.2 (0x03060A000002)
*May 28 16:18:06.131: Se1/0 IPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:18:06.134: Se1/0 CDPCP: I CONFACK [ACKsent] id 1 len 4
*May 28 16:18:06.135: Se1/0 CDPCP: Event[Receive ConfAck] State[ACKsent to Open] *May 28 16:18:06.140: Se1/0 IPCP: State is Open
*May 28 16:18:06.140: Se1/0 CDPCP: State is Open
*May 28 16:18:06.143: Se1/0 Added to neighbor route AVL tree: topoid 0, address 10.0.0.1
*May 28 16:18:06.144: Se1/0 IPCP: Install route to 10.0.0.1
*May 28 16:18:07.935: %DUAL-5-NBRCHANGE: EIGRP-IPv4 100: Neighbor 10.0.0.1 (Serial1/0) is up: new adjacency

R2#sh ppp all
Interface/ID OPEN+ Nego* Fail- Stage Peer Address Peer Name
———— ——————— ——– ————— ——————–
Se1/0 LCP+ CHAP+ IPCP+ CDP> LocalT 10.0.0.1 R1

 

Leave a Comment

*