debug ppp negotiation
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.
Pay Attention for it, most of the other debug command are in a similar formation.
- The timestamp—Millisecond timestamps are useful.
- 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.
- Type of PPP message—This field indicates whether the line is a general PPP, LCP, CHAP, PAP, or IPCP message.
- 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.
- Message—This field includes the particular transaction under negotiation.
- 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.
- 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!--- The Physical Layer (BRI Interface) is up. Only now can PPP
PPP protocol negotiation debugging is on
CetaMax_01#
*Mar 1 00:06:36.645: %LINK-3-UPDOWN: Interface BRI0:1, changed state to up
!--- negotiation begin.
*Mar 1 00:06:36.661: BR0:1 PPP: Treating connection as a callin!--- The PPP Phase is ESTABLISHING. LCP negotiation now occurs.
*Mar 1 00:06:36.665: BR0:1 PPP: Phase is ESTABLISHING, Passive Open[0 sess, 0 load]
*Mar 1 00:06:36.669: BR0:1 LCP: State is Listen!--- This is the incoming CONFREQ. The ID field is 7.
*Mar 1 00:06:37.034: BR0:1 LCP: I CONFREQ [Listen] id 7 len 17
*Mar 1 00:06:37.038: BR0:1 LCP: AuthProto PAP (0x0304C023)!--- The peer has requested:
*Mar 1 00:06:37.042: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
*Mar 1 00:06:37.046: BR0:1 LCP: Callback 0 (0x0D0300)
!--- 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)!--- This router requests:
*Mar 1 00:06:37.062: BR0:1 LCP: MagicNumber 0x1081E7E1 (0x05061081E7E1)
!--- 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)!--- The peer can support all requested parameters.
*Mar 1 00:06:37.106: BR0:1 LCP: MagicNumber 0x1081E7E1 (0x05061081E7E1)
*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)!--- The peer has requested:
*Mar 1 00:06:37.121: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
!--- 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)!--- CHAP authentication is requested.
*Mar 1 00:06:37.173: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
*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)!--- This indicates that the LCP state is Open.
*Mar 1 00:06:37.185: BR0:1 LCP: MagicNumber 0x507A214D (0x0506507A214D)
*Mar 1 00:06:37.189: BR0:1 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!--- This is an incoming response from the peer.
*Mar 1 00:06:37.237: BR0:1 CHAP: I RESPONSE id 4 len 33 from "CetaMax_03"
*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!--- This is an incoming Success message. Each side has
*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
!--- 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!--- This is an outgoing CONFREQ message. It indicates that
*Mar 1 00:06:37.308: BR0:1 IPCP: Address 172.22.1.1 (0x0306AC160101)
!--- 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!--- These messages are for CDP Control Protocol (CDPCP).
*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
*Mar 1 00:06:37.332: BR0:1 IPCP: I CONFREQ [REQsent] id 4 len 10!--- This is an incoming CONFREQ message that indicates that the peer
*Mar 1 00:06:37.336: BR0:1 IPCP: Address 172.22.1.2 (0x0306AC160102)
!--- 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!--- The IPCP state is Open. Note that in the IPCP negotiation, each side
*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
!--- 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!--- This indicates that the CDPCP state is Open.
*Mar 1 00:06:37.375: BR0:1 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