debug ppp negotiation

In dial-related applications, PPP (Point-to-Point Protocol) is the most commonly used encapsulation type. PPP allows two machines on a p2p communication link to negotiate various parameters for authentication, compression, and the Layer 3 (L3) protocols, such as IP. A failure in the PPP negotiation between two routers causes the connection to fail.

PPP negotiation between two peers cannot start unless the lower layer (ISDN, physical interface, dial-up line, and so on) under PPP functions perfectly. For example, if you want to run PPP over ISDN, then all ISDN layers must be up; otherwise PPP does not start.

The debug ppp negotiation command enables you to view the PPP negotiation transactions, identify the problem or stage when the error occurs, and develop a resolution. So, it is imperative that you understand the debug ppp negotiation command output.

Phases of PPP Negotiation:

LCP (Mandatory Phase):

LCP is a phase in which parameters to establish, configure, and test the data-link connection are negotiated. An LCP state of open means that LCP was successfully completed, while an LCP state of closed indicates an LCP failure.

Output Field Explain:
Pay Attention for it, most of the other debug command are in a similar formation.

1. The timestamp—Millisecond timestamps are useful.
   
2. Interface and Interface number—This field is useful when debug connections use multiple connections, or when the connection transitions through several interfaces. For example, certain connections (such as multilink calls) are controlled by the physical interface at the beginning,but are later controlled by the dialer interface or virtual-access interface.
3. Type of PPP message—This field indicates whether the line is a general PPP, LCP, CHAP, PAP, or IPCP message.
4. Direction of the message—An I indicates an incoming packet, and an O indicates an outgoing packet. This field can be used to determine if the message was generated or received by the router.
5. Message—This field includes the particular transaction under negotiation.
6. ID—This field is used to match and coordinate request messages to the appropriate response messages. You can use the ID field to associate a response with an incoming message. This option is especially useful when the incoming message and the response are far apart in the debug output.
7. Length—The length field defines the length of the information field. This field is not important for general troubleshooting.

Example:

CetaMax_01#debug ppp negotiation
PPP protocol negotiation debugging is on
CetaMax_01#
*Mar 1 00:06:36.645: %LINK-3-UPDOWN: Interface BRI0:1, changed state to up

!--- The Physical Layer (BRI Interface) is up. Only now can PPP
!--- negotiation begin.

*Mar 1 00:06:36.661: BR0:1 PPP: Treating connection as a callin
*Mar 1 00:06:36.665: BR0:1 PPP: Phase is ESTABLISHING, Passive Open[0 sess, 0 load]

!--- The PPP Phase is ESTABLISHING. LCP negotiation now occurs.

*Mar 1 00:06:36.669: BR0:1 LCP: State is Listen
*Mar 1 00:06:37.034: BR0:1 LCP: I CONFREQ [Listen] id 7 len 17

!--- This is the incoming CONFREQ. The ID field is 7.

*Mar 1 00:06:37.038: BR0:1 LCP: AuthProto PAP (0x0304C023)
*Mar 1 00:06:37.042: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
*Mar 1 00:06:37.046: BR0:1 LCP: Callback 0 (0x0D0300)

!--- The peer has requested:
!--- Option: Authentication Protocol, Value: PAP
!--- Option: MagicNumber (This is used to detect loopbacks and is always sent.)
!--- Option: Callback, Value: 0 (This is for PPP Callback; MS Callback uses 6.)

*Mar 1 00:06:37.054: BR0:1 LCP: O CONFREQ [Listen] id 4 len 15

!--- This is an outgoing CONFREQ, with parameters for the peer to implement.
!--- Note that the ID Field is 4, so this is not related to the previous
!--- CONFREQ message.

*Mar 1 00:06:37.058: BR0:1 LCP: AuthProto CHAP (0x0305C22305)
*Mar 1 00:06:37.062: BR0:1 LCP: MagicNumber 0x1081E7E1 (0x05061081E7E1)

!--- This router requests:
!--- Option: Authentication Protocol, Value: CHAP
!--- Option: MagicNumber (This is used to detect loopbacks and is always sent.)

*Mar 1 00:06:37.066: BR0:1 LCP: O CONFREJ [Listen] id 7 len 7

!--- This is an outgoing CONFREJ for message with Field ID 7.
!--- This is the response to the CONFREQ received first.

*Mar 1 00:06:37.070: BR0:1 LCP: Callback 0 (0x0D0300)

!--- The option that this router rejects is Callback.
!--- If the router wanted to do MS Callback rather than PPP Callback, it
!--- would have sent a CONFNAK message instead.

*Mar 1 00:06:37.098: BR0:1 LCP: I CONFACK [REQsent] id 4 len 15

!--- This is an incoming CONFACK for a message with Field ID 4.

*Mar 1 00:06:37.102: BR0:1 LCP: AuthProto CHAP (0x0305C22305)
*Mar 1 00:06:37.106: BR0:1 LCP: MagicNumber 0x1081E7E1 (0x05061081E7E1)

!--- The peer can support all requested parameters.

*Mar 1 00:06:37.114: BR0:1 LCP: I CONFREQ [ACKrcvd] id 8 len 14

!--- This is an incoming CONFREQ message; the ID field is 8.
!--- This is a new CONFREQ message from the peer in response to the CONFREJ id:7.

*Mar 1 00:06:37.117: BR0:1 LCP: AuthProto PAP (0x0304C023)
*Mar 1 00:06:37.121: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)

!--- The peer has requested:
!--- Option: Authentication Protocol, Value: PAP
!--- Option: MagicNumber (This is used to detect loopbacks and is always sent.)

*Mar 1 00:06:37.125: BR0:1 LCP: O CONFNAK [ACKrcvd] id 8 len 9

!--- This is an outgoing CONFNACK for a message with Field ID 8.

*Mar 1 00:06:37.129: BR0:1 LCP: AuthProto CHAP (0x0305C22305)

!--- This router recognizes the option Authentication Protocol,
!--- but does not accept the value PAP. In the CONFNAK message,
!--- it suggests CHAP instead.

*Mar 1 00:06:37.165: BR0:1 LCP: I CONFREQ [ACKrcvd] id 9 len 15

!--- This is an incoming CONFREQ message with Field ID 9.

*Mar 1 00:06:37.169: BR0:1 LCP: AuthProto CHAP (0x0305C22305)
*Mar 1 00:06:37.173: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)

!--- CHAP authentication is requested.

*Mar 1 00:06:37.177: BR0:1 LCP: O CONFACK [ACKrcvd] id 9 len 15

!--- This is an outgoing CONFACK for a message with Field ID 9.

*Mar 1 00:06:37.181: BR0:1 LCP: AuthProto CHAP (0x0305C22305)
*Mar 1 00:06:37.185: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
*Mar 1 00:06:37.189: BR0:1 LCP: State is Open

!--- This indicates that the LCP state is Open.

*Mar 1 00:06:37.193: BR0:1 PPP: Phase is AUTHENTICATING, by both [0 sess, 0 load]

!--- The PPP Phase is AUTHENTICATING. PPP Authentication occurs now.
!--- Two-way authentication is now performed (indicated by the both keyword).

*Mar 1 00:06:37.201: BR0:1 CHAP: O CHALLENGE id 4 len 33 from "CetaMax_01"

!--- This is the outgoing CHAP Challenge.
!--- In LCP the routers had agreed upon CHAP as the authentication protocol.

*Mar 1 00:06:37.225: BR0:1 CHAP: I CHALLENGE id 3 len 33 from "CetaMax_03"

!--- This is an incoming Challenge message from the peer.

*Mar 1 00:06:37.229: BR0:1 CHAP: Waiting for peer to authenticate first
*Mar 1 00:06:37.237: BR0:1 CHAP: I RESPONSE id 4 len 33 from "CetaMax_03"

!--- This is an incoming response from the peer.

*Mar 1 00:06:37.244: BR0:1 CHAP: O SUCCESS id 4 len 4

!--- This router has successfully authenticated the peer.

*Mar 1 00:06:37.248: BR0:1 CHAP: Processing saved Challenge, id 3
*Mar 1 00:06:37.260: BR0:1 CHAP: O RESPONSE id 3 len 33 from "CetaMax_01"
*Mar 1 00:06:37.292: BR0:1 CHAP: I SUCCESS id 3 len 4

!--- This is an incoming Success message. Each side has
!--- successfully authenticated the other.

*Mar 1 00:06:37.296: BR0:1 PPP: Phase is UP [0 sess, 0 load]

!--- The PPP status is now UP. NCP (IPCP) negotiation begins.

*Mar 1 00:06:37.304: BR0:1 IPCP: O CONFREQ [Closed] id 4 len 10
*Mar 1 00:06:37.308: BR0:1 IPCP: Address 172.22.1.1 (0x0306AC160101)

!--- This is an outgoing CONFREQ message. It indicates that
!--- the local machine address is 172.22.1.1.

*Mar 1 00:06:37.312: BR0:1 CDPCP: O CONFREQ [Closed] id 4 len 4
*Mar 1 00:06:37.320: BR0:1 CDPCP: I CONFREQ [REQsent] id 4 len 4
*Mar 1 00:06:37.324: BR0:1 CDPCP: O CONFACK [REQsent] id 4 len 4

!--- These messages are for CDP Control Protocol (CDPCP).

*Mar 1 00:06:37.332: BR0:1 IPCP: I CONFREQ [REQsent] id 4 len 10
*Mar 1 00:06:37.336: BR0:1 IPCP: Address 172.22.1.2 (0x0306AC160102)

!--- This is an incoming CONFREQ message that indicates that the peer
!--- address is 172.22.1.2. An address of 0.0.0.0 indicates that the peer
!--- does not have an address and requests the local router to provide it
!--- with an address in IPCP negotiation.

*Mar 1 00:06:37.344: BR0:1 IPCP: O CONFACK [REQsent] id 4 len 10
*Mar 1 00:06:37.348: BR0:1 IPCP: Address 172.22.1.2 (0x0306AC160102)
*Mar 1 00:06:37.356: BR0:1 IPCP: I CONFACK [ACKsent] id 4 len 10
*Mar 1 00:06:37.360: BR0:1 IPCP: Address 172.22.1.1 (0x0306AC160101)
*Mar 1 00:06:37.363: BR0:1 IPCP: State is Open

!--- The IPCP state is Open. Note that in the IPCP negotiation, each side
!--- accepted the IP address of the peer, and one was assigned to the peer.

*Mar 1 00:06:37.371: BR0:1 CDPCP: I CONFACK [ACKsent] id 4 len 4
*Mar 1 00:06:37.375: BR0:1 CDPCP: State is Open

!--- This indicates that the CDPCP state is Open.

*Mar 1 00:06:37.387: BR0 IPCP: Install route to 172.22.1.2

!--- A route to the peer is installed.

*Mar 1 00:06:38.288: %LINEPROTO-5-UPDOWN: Line protocol on Interface BRI0:1, changed state to up
*Mar 1 00:06:42.609: %ISDN-6-CONNECT: Interface BRI0:1 is now connected to CetaMax_03