TCP/IP and Data Communications Administration Guide

Using PPP Diagnostics for Troubleshooting

If you have problems with a link after successfully establishing modem connections, you can use PPP-level diagnostics for troubleshooting. PPP-level diagnostics report detailed information about the activities of a link to help you determine where it is failing.

To obtain diagnostic information, add the line debug_level 8 to the path section of the asppp.cf file. (If you are very knowledgeable about data communications, you might want to use debug level 9, which provides very detailed information.) Here is a sample configuration file that invokes PPP diagnostics.


ifconfig ipdptp0 plumb nomada nubian-ppp up
path
   interface ipdptp0
   peer_system_name nubian-ppp   #The name in the /etc/uucp/Systems file
   inactivity_timeout 300        #Allow five minutes before timing out
   debug_level 8                 #Start up PPP diagnostics for this link

For complete details about the aspppd.conf file, refer to "Editing the /etc/asppp.cf Configuration File".

How to Set Diagnostics for Your Machine

Set diagnostics on the host you want to monitor as follows:

  1. Become superuser and change to the /etc directory.

  2. Edit the current asppp.cf file and add the following to the path section: debug_level 8.

  3. Save the file, making sure the permissions are set to 600.

  4. Kill the current aspppd daemon and restart it.


    #kill PID
    #aspppd
    

    where PID is the process ID for aspppd.

    PPP reports diagnostic information in /var/adm/log/asppp.log.

Analyzing Diagnostic Output

When a PPP link runs correctly, the asppp.log file includes diagnostic information in addition to its normal output. This section explains what the diagnostic messages mean. If your output is different, refer to RFC 1331.

Host and Modem Setup

This section contains messages that occur as the local host sends configuration information to the modem, and then as the modem tries to dial the remote host. These initial activities are actually handled by the UUCP daemon. You might think of them as the UUCP portion of asynchronous PPP communications. (Refer to Chapter 12, UUCP Databases and Programs, for complete details on UUCP.)

The two messages below should always appear at the beginning of the session. They indicate that the aspppd daemon has started successfully.


11:53:33 Link manager (1057) started 04/14/94
11:53:33 parse_config_file: Successful configuration

The next line indicates that a packet was routed to the ipdptp0 interface on the local host. It helps you to determine if a dial-out is occurring correctly. For example, if you tried to ping the remote machine and this message isn't in asppp.log, the packet was lost, probably due to a routing problem.

Next, UUCP looks for an entry that matches Ppac7 in a chat script in the /etc/uucp/Systems file. It then reports that it found an entry that had a device type ACUTEC. (For more information on the Systems file, refer to "/etc/uucp/Systems File".)


11:53:46 process_ipd_msg: ipdptp0 needs connection
conn(Ppac7)
Trying entry from '/etc/uucp/Systems' - device type ACUTEC.

UUCP then finds the dialing information for an ACUTEC dialer in the /etc/uucp/Devices file. When it finds the information, it opens the appropriate serial port on the local host and sets it with a speed of 9600. (For more information on /etc/uucp/Devices, see "/etc/uucp/Devices File".)


Device Type ACUTEC wanted
Trying device entry 'cua/a' from '/etc/uucp/Devices'.
processdev: calling setdevcfg(ppp, ACUTEC)
fd_mklock: ok
fixline(8, 9600)
gdial(tb9600-ec) calle

UUCP looks for the entry tb9600 in the /etc/uucp/Dialers file and then sends out these messages.


Trying caller script 'tb9600-ec' from '/etc/uucp/Dialers'
expect: ("")

The host waits a couple of seconds and then sets the registers on the modem. The information shown in the log below is modem-specific. It comes from the /etc/uucp/Dialers file.


got it
sendthem (DELAY)
APAUSE
APAUSE
APAUSE
T&D2E1V1X1Q0S2=255S12=255S50=6S58=2^M<NO CR>)

The next lines are the dialog between the modem and the host machine. expect (OK^M) means that the host expects the modem to send an "okay." The words got it at the end of the second line indicate that the host got the "okay" message from the modem.


expect: (OK^M)
AAAT&D2E1V1X1Q0S2=255S12=255S50=6S58=2^M^M^JOK^Mgot it

Next, the host sends the string below to the modem, which does the actual dialing. The phone number in the second line is retrieved from the entry for the remote host in the /etc/uucp/Systems file.


sendthem (ECHO CHECK ON
A^JATTDDTT99003300887744^M^M<NO CR>)

The line beginning with expect indicates that the local host expects to get a response from the modem at a speed of 9600 bps. The next line indicates that the modem responded.


expect: (CONNECT 9600)
^M^JCONNECT 9600got it

This line indicates that hardware flow control has started on the link. The host obtains flow control information from the /etc/uucp/Dialers file.


STTY crtscts

In the next series of messages, the local host waits for the remote host to send it a standard UNIX login prompt.


getty ret 8
expect: ("")
got it
sandiest (^J^M)
expect: (login:)

The next messages indicate that the local host has received the login prompt from the remote. It then retrieves the appropriate login sequence from the chat script in the /etc/uucp/Systems entry for the remote host. This sequence is Ppong^M, which is required for login by the remote host.


^M^J^M^Jlogin:got it
sendthem (Ppong^M)

In these messages, the local host waits for the ssword prompt from the remote host. Upon receipt of the prompt, the local host sends the password retrieved from the chat script in the /etc/uucp/Systems entry for the remote host.


expect: (ssword:)
login: Ppong^M^JPassword:got it

The following messages indicate that dialing and modem connection completed successfully.


sendthem (ppptest1^M)
call cleanup(0)^M

Communications Between the Local and Remote Hosts

At this point, PPP communications start, as the link between local and remote hosts is now established.

The first lines in this part of the session constitute a configuration request (Config-Req). This is the first PPP packet sent to the remote host. The configuration request is one example of a Link Control Protocol (LCP) packet. It requests that configuration be set up and then sets up the PPP link between endpoint machines. Example 10-4 shows a sample configuration request.


Example 10-4 Configuration Request


11:54:20 004298 ipdptp0 SEND PPP ASYNC 29 Octets LCP Config-Req 
ID=4c LEN=24 MRU=1500 ACCM=00000000 MAG#=69f4f5b2 ProtFCOMP
AddrCCOMP

Here is a description of the configuration request shown in Example 10-4.

The remaining items are a list of options to be negotiated between hosts.

The next lines are reporting invalid PPP packets. They come from the remote host, which is sending out UNIX text. This does not indicate a problem with PPP.


11:54:20 004299 ipdptp0 RECEIVE {Invalid ppp packet}PPP ASYNC 7
Octets [BAD FCS] {Unrecognized protocol:    1}

11:54:20 004299 ipdptp0 RECEIVE PPP ASYNC 73 Octets [BAD FCS]
{Unrecognized protocol:    880a}

In these packets, the local host receives the remote host's request for configuration, then sends out another configuration request. The packets are identical except for their ID fields. The ID field helps to distinguish between the two packets.


11:54:21 004301 ipdptp0 RECEIVE PPP ASYNC 29 Octets LCP Config-
Req  ID=35 LEN=24 MRU=1500 ACCM=00000000 MAG#=a8562e5f ProtFCOMP
AddrCCOMP

11:54:21 004302 ipdptp0 SEND PPP ASYNC 29 Octets LCP Config-Req 
ID=4d LEN=24 MRU=1500 ACCM=00000000 MAG#=69f4f5b2 ProtFCOMP
AddrCCOMP

In this packet, the local host acknowledges the remote request by sending it a configuration acknowledgment (Config-ACK).


11:54:21 004303 ipdptp0 SEND PPP ASYNC 29 Octets LCP Config-ACK 
ID=35 LEN=24 MRU=1500 ACCM=00000000 MAG#=a8562e5f ProtFCOMP
AddrCCOMP

The local host receives a configuration request (Config-Req) from the remote host.


11:54:21 004304 ipdptp0 RECEIVE PPP ASYNC 29 Octets LCP Config-
Req  ID=36 LEN=24 MRU=1500 ACCM=00000000 MAG#=a8562e5f ProtFCOMP
AddrCCOMP

In these packets, the local host acknowledges the second packet sent by the remote host and receives the remote host's acknowledgment.


11:54:21 004305 ipdptp0 SEND PPP ASYNC 29 Octets LCP Config-ACK 
ID=36 LEN=24 MRU=1500 ACCM=00000000 MAG#=a8562e5f ProtFCOMP
AddrCCOMP

11:54:21 004306 ipdptp0 RECEIVE PPP ASYNC 29 Octets LCP Config-
ACK  ID=4d LEN=24 MRU=1500 ACCM=00000000 MAG#=69f4f5b2 ProtFCOMP
AddrCCOMP

Here the local host negotiates parameters about IP transmission. LEN=16 gives the packet size. VJCOMP indicates Van Jacobsen header compression. IPADDR is followed by the calling host's IP address.


11:54:21 004307 ipdptp0 SEND PPP ASYNC 21 Octets IP_NCP Config-
Req  ID=4e LEN=16 VJCOMP MAXSID=15 Sid-comp-OK IPADDR=192.9.68.70

This packet indicates that the local host has received IP configuration from the remote host, including its IP address.


11:54:22 004308 ipdptp0 RECEIVE PPP ASYNC 21 Octets IP_NCP
Config-Req  ID=37 LEN=16 VJCOMP MAXSID=15 Sid-comp-OK
IPADDR=192.9.68.71

The local host sends this ACK to the remote host and receives an ACK from the remote host.


11:54:22 004309 ipdptp0 SEND PPP ASYNC 21 Octets IP_NCP Config-
ACK  ID=37 LEN=16 VJCOMP MAXSID=15 Sid-comp-OK IPADDR=192.9.68.71

11:54:22 004310 ipdptp0 RECEIVE PPP ASYNC 21 Octets IP_NCP
Config-ACK  ID=4e LEN=16 VJCOMP MAXSID=15 Sid-comp-OK
IPADDR=192.9.68.70

The first message below indicates that IP has started on the link. The next message indicates that the local host is sending IP traffic over the link.


11:54:22 start_ip: IP up on interface ipdptp0, timeout set for
120 seconds

11:54:24 004311 ipdptp0 SEND PPP ASYNC 89 Octets IP_PROTO

In the first message below the local host receives IP traffic from the remote host. The subsequent messages indicate that the interface was disconnected because of an idle time-out.


11:54:25 004312 ipdptp0 RECEIVE PPP ASYNC 89 Octets IP_PROTO
11:56:25 process_ipd_msg: interface ipdptp0 has disconnected
11:56:25 disconnect: disconnected connection from  ipdptp0

The next messages begin the termination sequence. The first message indicates that the remote host has sent a packet to terminate the IP layer. The second is the local host's acknowledgment of the request to terminate.


11:56:25 004313 ipdptp0 RECEIVE PPP ASYNC 9 Octets IP_NCP Term-
REQ  ID=38 LEN=4

11:56:25 004314 ipdptp0 SEND PPP ASYNC 9 Octets IP_NCP Term-ACK 
ID=38 LEN=4

The local host receives a request to terminate the LCP layer. The second message is an acknowledgment of the request, causing a graceful shutdown.


11:56:25 004315 ipdptp0 RECEIVE PPP ASYNC 9 Octets LCP Term-REQ 
ID=39 LEN=4

11:56:25 004316 ipdptp0 SEND PPP ASYNC 9 Octets LCP Term-ACK 
ID=39 LEN=4

This message indicates that the link has closed.


11:56:29 004317 ipdptp0 PPP DIAG CLOSE