Using the Server Log


Understanding the Server Log

The server log contains information about most server activities, such as who connected to the server, what discussion groups were read, what articles were posted, and what problems occurred.

Messages are numbered according to priority, with lower numbers representing higher-priority messages. The number can be found in the log entry after the last colon. Highest-priority messages, usually indicating an error condition that requires some action on your part, appear in red. For example, the entry [99/07/12 15:53.41] innd:indexer-special opened indexer-special:6:file indicates a level 6 priority.

A typical message you might see in the server log shows the message format:

3 [96/06/19 04:00.58] innd:ME new client starting:  "/news/ns-news-pb2/bin/news/bin/nnrpd -s -i 204.257.234.169"

If you are having problems with your server, the server log is the first place you should look for information. The information you see depends on the log level specified: Debug, Fatal, Error, or Notice. Debug lists all messages. Notice lists a minimal number of messages.

The server log is archived each time the server's daily maintenance routines are run.


Processes that Log Messages

The processes that frequently send messages to both the server and discussion replication logs are listed in the following table.

Process Description

innd

The main server process that handles all discussion group replications, listens to the specified news port, and responds to connections from newsreaders.

nnrpd

The server process that spawns a thread for each newsreader it is handling. The nnrpd process is sometimes referred to as "reader process" or "reader processes" and is invoked by innd.

nntpsend

The process that batches discussion group replications for transmittal by the innxmit process.

innxmit

The process that transmits articles to servers. The nntpsend process invokes this process.

indexer

The process that indexes articles for full-text searching purposes.

newstime

The process that schedules jobs, such as running news.daily, updating profiles, the nntpsend process, and so on.

ns-admin

The administration server process.


Viewing the Server Log

To determine the number of log cycles and the level of detail in the server replication log, refer to Specifying Logging Preferences.

  1. From the General Administration page, click the News Server server name button > Reports > View Server Log.

  2. Select the log you want to view.

  3. Type the number of entries you want to view.

  4. In the View Only Entries Containing field, type a search string if you want to find specific entries.

    For example, if you want to see information about errors, type Errors in the search field.

  5. Click View Log.


Interpreting the Server Log

The following section provides examples of server log messages and how to interpret them.


Client Connection Information

Client connection information provides a record of who has been accessing your server. These messages are informational only and do not indicate an error or problem.

The following message indicates that the main process (innd) is starting a new reader and handing off the connection to a reader process (nnrpd). The connecting client has the IP address 204.257.234.169.

3 [96/06/19 04:00.58] innd:ME new client starting:"/news/ns-news-pb2-bin/news/bin/nnrpd -s -i 204.257.234.169

The next message indicates that the nnrpd process has accepted the handoff for the above connections. (Notice that the IP address is the same.)

3 [96/06/19 4:00.59] nnrpd (5): Starting new reader, got socket: 22 and cmdline:"/news/ns-news-pb2/bin/news/bin/nnrpd -s -i 204.257.234.169" from innd

The next message indicates that the host TS368.DIALUP.PREM.NET has successfully connected. (This host has IP address 204.257.234.169, so it is the same host as in the previous two messages.)

3 [96/06/19 04:01.02] nnrpd(5):ts369.dialup.prem.net connect

Normal Client Session and Disconnects

During a client session and when a client disconnects, the client process logs informational messages about the sessions. Some of this information is used by the daily report to generate statistics.

The following message indicates that the connected client read three articles in the discussion group SUPPORT.NOVELL:

3 [96/06/19 04:01.02] nnrpd(2):245.dallas-3.tx.dial-access.att.net group support.novell 3

The next message indicates that the client read a total of three articles in one discussion group during its session, then disconnected from the server:

3 [96/06/19 04:01.02] nnrpd(2):245.dallas-3.tx.dial-access.att.net exit articles 3 groups 1

The next message indicates that the client was connected a total of 1662.313 seconds, used 3.360 seconds of CPU time for user code, and 0.620 seconds for system code:

3 [96/06/19 04:01.02] nnrpd(2):245.dallas-3.tx.dial-access.att.net times user 3.360 system 0.620 elapsed 1662.313

Abnormal Client Disconnects

Abnormal client disconnect messages indicate that a client is acting improperly. You can generally ignore these types of messages.

The following message indicates that a client has attempted to connect to the news port, but was unable to do so:

2 [96/06/19 04:00.58] innd:ME cant accept RCreader Protocol error

You might see this message if a client that is not a newsreader attempts to connect to the news port. Because the server and the connecting program do not use the same protocol, they cannot communicate, so innd closes the connection. In most cases, you can ignore this message.

The next message indicates the network connection has been closed due to a timeout:

3 [96/06/19 04:01.02] nnrpd(2):245.dallas-3.tx.dial-access.att.net timeout

Most news clients send a quit message when they are finished. However, some clients do not send quit messages. Normally, the server keeps the network connection open until it receives a quit message. However, if a certain amount of time has passed and the client has not sent anything to the server, the server closes the connection. This is called a timeout, which you can safely ignore.


Incoming Discussion Groups

Incoming discussion groups are articles sent to your server from other servers.

The following example message indicates that the server NEWS.FOO.COM connected and sent 31 articles to your server. Your server accepted 29, refused 1, and rejected 1.

[96/07/15 15:58.03] innd:news.foo.com:29 closed seconds 12 accepted 29 refused 1 rejected 1

Outgoing Discussion Groups

Outgoing discussion groups are articles sent by your server to other servers.

The following message indicates that your server is sending articles to another server (called SECNEWS in this example). Your server offered one article, which was rejected:

[96/06/19 04:25.06] nntpsend:[28260:28261] innxmit -a -t180  secnews.netscape.com...[96/06/19 04:25.07] innxmit:secnews.netscape.com stats offered 1  accepted 0 refused 0 rejected 1[96/06/19 04:25.07] innxmit:secnews.netscape.com times user 0.180 system 0.060 elapsed 0.453

If only one article is rejected, you need not worry. If, however, all your articles are refused or rejected, you should contact the administrator of the other server. If the administrator of the other server indicates that the server is not receiving your replicated discussion groups, check for the following status messages in your log file:

4 [96/06/19 04:05.04] innd:E:secnews.netscape.com:secnews.netscape.com.work [96/06/19 04:05.04] innd:secnews.netscape.com makebatch->secnews.netscape.com.work[96/06/19 04:05.04] innd:secnews.netscape.com closed[96/06/19 04:05.04] innd:secnews.netscape.com opened secnews.netscape.com:23:file

These messages indicate that the innd process has created a batch file containing article information to send to the server SECNEWS. Check to see if nntpsend and innxmit are running. If they are not, make sure SECNEWS is configured as a replication host in the Configure Replication Host form (from the General Administration form, click Discussion Replication > Configure Replication Host).


Server Load Information

The server process (innd) occasionally asks the reader processes (nnrpd) for status. Each reader process provides information about the number of clients it is handling. Next, innd notes the active value for future load balancing efforts. The reader process messages are informational only and do not indicate an error or problem.


Innd Errors

Server errors generally indicate a problem with the server that must be investigated and corrected if necessary.

The following message indicates an error occurred when innd was attempting to write information to a sending host. The error number, 10054, indicates that the connection was reset, which usually means that the sending host closed the connection early:

2 [96/08/16 15:20.50] innd:257.0.180.15:7 can't write [Errno:10054]

If you see a lot of these messages and your incoming discussion groups from that site (257.0.180.15 in this case) seem to be lacking, contact the administrator of the other site and see why the connection is getting dropped.

The next message indicates that innd can't communicate with an nnrpd process that it expects is running:

2 [96/08/16 17:00.38] innd:unable to query nnrpd(0): 232

The nnrpd has hung.

The following message indicates that your ACTIVE file is bad.

2 [96/06/29 04:15.11] innd:ME bad_format active

The next message indicates that innd couldn't delete a file. Normally this is not a problem, but it can be a symptom of another problem. If you start to see a lot of these messages, check for other problems, such as problems with permission or ownership.

2 [96/07/07 21:10.34] innd:ME cant unlink

The next message indicates that innd couldn't link an article file. (Article files are linked when an article is cross-posted to save space.) The linking can fail for various reasons, including one of the link names existing as a regular file. If you get the following message too often, try renumbering your ACTIVE file in the Server Recovery form (from the News Server interface, click Advanced Tasks > Recovery.)

2 [96/07/25 19:08.17] innd:ME cant link talk/politics/misc/965

ACTIVE File Errors

The ACTIVE file contains information about all the discussion groups your server carries. The ACTIVE file might contain a formatting error, an invalid discussion group name, an illegal discussion group name, duplicate discussion group names, or incorrectly formatted lines.

The following message indicates that the two required discussion groups, control and junk, do not exist. Without these groups, the server will not run:

1 [96/06/24 09:29.43] innd:ME internal no control and/or junk group

You can add the groups through the Discussion Group Manager (from the News Server interface, click Discussion Groups > Manage Discussion Groups > OK) or you can remake the ACTIVE file in the Server Recovery form (from the News Server interface, click Advanced Tasks > Recovery) if the groups exist but are not in the ACTIVE file.

The next message indicates that discussion groups listed in your ACTIVE file have invalid names according to RFC1036, the Internet standards document that defines valid newsgroup names.

2 [96/07/09 11:14.37] ctlinnd:parseactive invalid newsgroup name2 [96/06/21 20:23.29] ctlinnd:parseactive invalid newsgroup name "GPsemi.lincoln.test3": Illegal

The discussion group name might be in uppercase, for example, or might contain numbers, such as FOO.COM.752.

You can rename the group or remove the group. Although it is not recommended, you can override group name validity checking by changing the REQUIRE_VALID1036_NAMES parameter value in the NSNEWS.CONFfile from DO to DONT. If you change the value, be aware that doing so might cause server problems. For example, your server's replication with fail to hosts that have the parameter set to DO.

The next message indicates a failure to write to the HISTORY file. The News Server stores information about all articles in a file called HISTORY. If the News Server cannot write to the HISTORY file, disk configuration problems and corruption of files can occur. The News Server will be unable to expire articles or to accept new articles:

2 [96/07/25 19:08.18] innd:ME cant write history  [Errno:10009]

Check for permission problems and lack of disk space. After fixing the problem, you will need to restart your server. You might also want to rebuild your HISTORY files, but this can take several hours, depending on the size of the HISTORY file and the number of articles on the server.

The next message indicates a failure to flush the log files. The server flushes the log files when running news.daily, for example, or when rotating log files. The server names the backup log file NAME.OLD.

inte2 [96/06/24 09:29.43] innd:ME cant fflush log [Errno:9]

The error code indicates that there is a bad descriptor. Try stopping the server and restarting it.



Previous | Next