Understanding the Log File

Error and status messages for Solstice PPP are written to the log file /var/opt/SUNWconn/ppp.log. See "Status and Error Messages" for a complete list of the messages which may appear in the log file.

The log file can grow very large and should be truncated regularily.

Successful Connection Attempt

The following log file extract shows the messages logged when Solstice PPP is started successfully on a client, and a connection to a remote server is opened and then disconnected:

11/14/95 15:32:55 - Link manager (904) has started 11/14/95
11/14/95 15:32:55 - Successful configuration
11/14/95 15:33:06 - Connection requested to miles
11/14/95 15:33:07 - Dialing number P365 ...
11/14/95 15:33:40 - Got modem connection
11/14/95 15:33:42 - LCP up on ipdptp0
11/14/95 15:33:42 - IP_NCP up on ipdptp0
11/14/95 15:33:42 - IP up on interface ipdptp0, with timeout set
to 120 seconds
11/14/95 15:35:41 - Disconnect indication on ipdptp0
11/14/95 15:35:41 - IP_NCP down on ipdptp0
11/14/95 15:35:42 - LCP down on ipdptp0

The corresponding log file on the server shows the messages logged when the incoming connection is accepted and then disconnected:

11/14/95 15:28:58 - Received a call on pppdev0
11/14/95 15:28:59 - Using dialup_path with expect_login_id ppp2
11/14/95 15:28:59 - LCP up on ipdptp0
11/14/95 15:28:59 - IP_NCP up on ipdptp0
11/14/95 15:29:00 - IP up on interface ipdptp0, with timeout set
to 120 seconds
11/14/95 15:30:59 - interface ipdptp0 has been disconnected
11/14/95 15:30:59 - Device pppdev0 has been disconnected

Problems Configuring Solstice PPP

When Solstice PPP is started, it reads the configuration files that you created using the configuration script pppinit. If these files do not exist, Solstice PPP displays the following message:

starting ppp (not configured)

The following log file extract shows the log messages that are generated when one of the configuration files contains an error:

11/13/95 18:53:22 - Link manager (460) has started 11/13/95
11/13/95 18:53:22 - parse_config_file: unrecognized symbol
nactivity_timeout
11/13/95 18:53:22 - parse_config_file: unrecognized symbol 180
11/13/95 18:53:22 parse_config_file: Errors in configuration file
/etc/opt/SUNWconn/ppp/ppp.conf

In this example, there is an unrecognised keyword contained in the file ppp.conf, which is rejected when the file is parsed. Check the configuration files for typographical errors and illegal values assigned to keywords. Restart Solstice PPP to read the configuration.

Problems Getting the Modem Connection

The first step in the connection phase is the modem connection. The client dials the telephone number of the modem connected to the server, and the two modems communicate to set up the connection.

The following log file extract shows the log messages that are generated when a client fails in an attempt to establish the modem connection:

11/13/95 19:57:44 - Connection requested to miles
11/13/95 19:57:45 - Dialing number P365 ...
11/13/95 19:58:09 - remote host is busy

The connection request never reaches the server; therefore, there are no corresponding messages in the log file on the server.

The message remote host is busy is displayed whenever the client fails to make the modem connection. This may mean that the server modem is already in use by another client, or that it has failed to terminate a previous connection cleanly. It may also mean that there is a problem with the equipment. In this example, the error was provoked by using tone dialing with an office exchange that expected pulse dialing.

Try telephoning the number directly to make sure that you can reach the modem. If you cannot reach the modem, check the telephone number the client is dialing.

Problems with the CHAT Script

The CHAT scrip is executed automatically each time a client initiates a call. It is used to exchange information with the server during the connection phase.

The following log file extract shows the log messages generated when the client did not receive the response it expected from the server:

11/14/95 15:38:52 - Connection requested to miles
11/14/95 15:38:53 - Dialing number P365 ...
11/14/95 15:39:35 - Got modem connection
11/14/95 15:39:53 - Timeout expired
11/14/95 15:40:03 - Timeout expired
11/14/95 15:40:13 - Timeout expired
11/14/95 15:40:23 - Timeout expired
11/14/95 15:40:23 - fail at line 18 in chat script /etc/opt/
SUNWconn/ppp/script/miles.scr

The following log file extract shows the log messages generated when the client did not send the response expected by the server:

11/14/95 15:58:03 - Connection requested to miles
11/14/95 15:58:04 - Dialing number P365 ...
11/14/95 15:58:37 - Got modem connection
11/14/95 15:59:16 - Timeout expired
11/14/95 15:59:16 - fail at line 25 in chat script /etc/opt/
SUNWconn/ppp/script/miles.scr

In some circumstances, an error in the CHAT script can provoke a loopback condition when the login sequence is not completed successfully. The following log file extract show the error messages generated by a loopback condition:

11/14/95 15:45:05 - Connection requested to miles
11/14/95 15:45:06 - Dialing number P365 ...
11/14/95 15:45:42 - Got modem connection
11/14/95 15:45:58 - PPP error on ipdptp0: Loop back detected
11/14/95 15:45:58 - Check if your connect script is correct.
11/14/95 15:45:58 - Or PPP may not be started on the remote host

Problems with PPP Negotiation

Once you have a modem connection and completed the login phase, the next step in the connection phase is the PPP negotiation. The client and the server communicate to negotiate a common configuration for the PPP link. The policy is to converge if at all possible; however, failure to agree on certain mandatory parameters will cause the negotiation to fail, as shown in the following log file extract:

11/13/95 20:34:42 - Connection requested to miles
11/13/95 20:34:43 - Dialing number P365 ...
11/13/95 20:35:16 - Got modem connection
11/13/95 20:35:19 - LCP up on ipdptp0
11/13/95 20:35:19 - PPP error on ipdptp0: Negotiation of mandatory
options failed

Problems with PAP and CHAP Authentication

The following log file extract shows what happens when a client fails to respond to a request for authentication:

11/14/95 10:22:41 - Connection requested to miles
11/14/95 10:22:42 - Dialing number P365 ...
11/14/95 10:23:16 - Got modem connection
11/14/95 10:23:47 - PPP error on ipdptp0: Maximum number of
configure requests exceeded

In this example, the server requested PAP authentication and the client rejected the request. After a specified number of requests, the server broke the connection without starting the PPP negotiation.

The following log file extract shows what happens when the client responds to the request for authentication with the wrong password:

11/14/95 15:20:04 - Connection requested to miles
11/14/95 15:20:04 - Dialing number P365 ...
11/14/95 15:20:09 - Got modem connection
11/14/95 15:20:09 - LCP up on ipdptp0
11/14/95 15:20:09 - PPP error on ipdptp0: Negotiation of mandatory
options failed

In both cases, the server sees a failed PPP negotiation and generates the following log file messages:

11/14/95 15:20:08 - Received a call on pppdev0
11/14/95 15:20:09 - Using dialup_path with expect_login_id ppp2
11/14/95 15:20:09 - PPP error on ipdptp0: Negotiation of mandatory
options failed
11/14/95 15:20:09 - Device pppdev0 has been disconnected

Problems with the Inactivity Timeout

The inactivity timeout closes the connection automatically when it remains unused for a specified number of seconds. This means that you do not pay for telephone connections that are left open accidently. However, if the inactivity timeout is too short, your connection may be closed prematurely.

The following log file extract shows an inactivity timeout triggered by the client after 60 seconds:

11/13/95 18:00:03 - IP up on interface ipdptp0, with timeout set
to 60 seconds
11/13/95 18:00:14 - Interface ipdptp0 has timed out

If the connection times out systematically, increase the inactivity timeout for calls to the server.

The following log file extract shows a connection that has been disconnected by the server for some reason. One possible cause is an inactivity timeout on the server that is shorter than the inactivity timeout on the client. It may also have been caused by a normal disconnect request from the server side.

11/13/95 18:13:46 - IP up on interface ipdptp0, with timeout set
to 240 seconds
11/13/95 18:15:47 - interface ipdptp0 has been disconnected