Chapter 13   Logging and Log Analysis


iPlanet Messaging Server can create log files that record events related to its administration, to communications using any of the protocols (SMTP, POP, IMAP, and HTTP) that the server supports, and to other processes employed by the server. By examining the log files, you can monitor many aspects of the server's operation.

Because the MTA uses a separate logging facility than the other services, you cannot use iPlanet Console to configure logging services and view logs. Instead, you configure MTA logging by specifying information in configuration files. Consequently this chapter is divided into three parts. The first part describes general introductory information; the second part describes logging for the message store and administration services; the third part describes logging for the MTA service.

"PART 1: Introduction"

"PART 2: Service Logs (Message Store, Administration Server, and MTA)"

"PART 3: Service Logs (MTA)"

PART 1: Introduction

---

You can customize the policies for creating and managing the Messaging Server log files. This chapter describes the types and structure of log files, and discusses how to administer and how to view the log files. It consists of the following sections:

• "Logged Services"

• "Analyzing Logs with Third-Party Tools"

Logged Services

Messaging Server creates a separate set of log files for each of the major protocols, or services, it supports. You can customize and view each type of log file individually. Table 13-1 lists the services that can be logged, and describes the log files for each service.

Table 13-1    Logged Services

Service	Log-file description
Admin	Contains logged events related to communication between iPlanet Console and Messaging Server (mostly through several CGI processes), by way of its Administration Server
SMTP	Contains logged events related to SMTP activity of this server
IMAP	Contains logged events related to IMAP4 activity of this server
POP	Contains logged events related to POP3 activity of this server
HTTP	Contains logged events related to HTTP activity of this server
Default	Contains logged events related to other activity of this server, such as command-line utilities and other processes

Analyzing Logs with Third-Party Tools

For log analyses and report generation beyond the capabilities of iPlanet Messaging Server, you need to use other tools. You can manipulate log files on your own with text editors or standard system tools.

With a scriptable text editor supporting regular-expression parsing, you can potentially search for and extract log entries based on any of the criteria discussed in this chapter, and possibly sort the results or even generate sums or other statistics.

In UNIX environments you might also be able to modify and use existing report-generation tools that were developed to manipulate UNIX syslog files. If you wish to use a public-domain syslog manipulation tool, remember that you may need to modify it to account for the different date/time format and for the two extra components (facility and logLevel) that appear in Messaging Server log entries but not in syslog entries.

PART 2: Service Logs (Message Store, Administration Server, and MTA)

---

This section describes logging for the following services: POP, IMAP, HTTP, MTA, Admin, and Default (see Table 13-1).

For these services, you can use iPlanet Console to specify log settings and to view logs. The settings you specify affect which and how many events are logged. You can use those settings and other characteristics to refine searches for logged events when you are analyzing log files. For additional information on service logs for the MTA see "PART 3: Service Logs (MTA)".

Part 2 contains the following sections:

• "Log Characteristics"

• "Log File Format"

• "Defining and Setting Logging Options"

• "Searching and Viewing Logs"

Log Characteristics

This section describes the following log characteristics for the message store and administration services: logging levels, categories of logged events, filename conventions for logs, and log-file directories.

Logging Levels

The level, or priority, of logging defines how detailed, or verbose, the logging activity is to be. A higher priority level means less detail; it means that only events of high priority (high severity) are logged. A lower level means greater detail; it means that more events are recorded in the log file.

You can set the logging level separately for each service—POP, IMAP, HTTP, Admin, and Default by setting the logfile.service.loglevel configuration parameter (see Defining and Setting Logging Options). You can also use logging levels to filter searches for log events. Table 13-2 describes the available levels. These logging levels are a subset of those defined by the UNIX syslog facility.

Table 13-2    Logging Levels for Store and Administration Services

Level	Description
Critical	The minimum logging detail. An event is written to the log whenever a severe problem or critical condition occurs—such as when the server cannot access a mailbox or a library needed for it to run.
Error	An event is written to the log whenever an error condition occurs—such as when a connection attempt to a client or another server fails.
Warning	An event is written to the log whenever a warning condition occurs—such as when the server cannot understand a communication sent to it by a client.
Notice	An event is written to the log whenever a notice (a normal but significant condition) occurs—such as when a user login fails or when a session closes.
Information	An event is written to the log with every significant action that takes place—such as when a user successfully logs on or off or creates or renames a mailbox.
Debug	The most verbose logging. Useful only for debugging purposes. Events are written to the log at individual steps within each process or task, to pinpoint problems.

When you select a particular logging level, events corresponding to that level and to all higher (less verbose) levels are logged. The default level of logging is Notice.

---

Note	The more verbose the logging you specify, the more disk space your log files will occupy; for guidelines, see Defining and Setting Logging Options.

---

Categories of Logged Events

Within each supported service or protocol, Messaging Server further categorizes logged events by the facility, or functional area, in which they occur. Every logged event contains the name of the facility that generated it. These categories aid in filtering events during searches. Table 13-3 lists the categories that Messaging Server recognizes for logging purposes.

Table 13-3    Categories in Which Log Events Occur 

Facility	Description
General	Undifferentiated actions related to this protocol or service
LDAP	Actions related to Messaging Server accessing the LDAP directory database
Network	Actions related to network connections (socket errors fall into this category)
Account	Actions related to user accounts (user logins fall into this category)
Protocol	Protocol-level actions related to protocol-specific commands (errors returned by POP, IMAP, or HTTP functions fall into this category)
Stats	Actions related to the gathering of server statistics
Store	Low-level actions related to accessing the message store (read/write errors fall into this category)

For examples of using categories as filters in log searches, see Searching and Viewing Logs.

Filename Conventions for Message Store and Administration Logs

Log files for the POP, IMAP, HTTP, Admin, and Default service use identical naming conventions. Each log file has a filename of the form:

service.sequenceNum.timeStamp

Table 13-4 lists the message store log filename conventions.

Table 13-4    Filename Conventions for Store and Administration Logs

Component	Definition
service	The service being logged: POP, IMAP, HTTP, Admin, Default.
sequenceNum	An integer that specifies the order of creation of this log file compared to others in the log-file directory. Log files with higher sequence numbers are more recent than those with lower numbers. Sequence numbers do not roll over; they increase monotonically for the life of the server (beginning at server installation).
timeStamp	A large integer that specifies the date and time of file creation. (Its value is expressed in standard UNIX time: the number of seconds since midnight January 1, 1970.)

For example, a log file named imap.63.915107696 would be the 63rd log file created in the directory of IMAP log files, created at 12:34:56 PM on December 31, 1998.

The combination of open-ended sequence numbering with a timestamp gives you more flexibility in rotating, expiring, and selecting files for analyzing. For more specific suggestions, see Defining and Setting Logging Options.

Log-File Directories

Every logged service is assigned a single directory, in which its log files are stored. All IMAP log files are stored together, as are all POP log files, and log files of any other service. You define the location of each directory, and you also define how many log files of what maximum size are permitted to exist in the directory.

Make sure that your storage capacity is sufficient for all your log files. Log data can be voluminous, especially at lower (more verbose) logging levels.

It is important also to define your logging level, log rotation, log expiration, and server-backup policies appropriately so that all of your log-file directories are backed up and none of them become overloaded; otherwise, you may lose information. See Defining and Setting Logging Options.

Log File Format

All message store and administration service log files created by Messaging Server have identical content formats. Log files are multiline text files, in which each line describes one logged event. All event descriptions, for each of the supported services, have the general format:

dateTime hostName processName[pid]: category logLevel: eventMessage

Table 13-5 lists the log file components. Note that this format of event descriptions is identical to that defined by the UNIX syslog facility, except that the date/time format is different and the format includes two additional components (category and logLevel).

Table 13-5    Store and Administration Log File Components

Component	Definition
dateTime	The date and time at which the event was logged, expressed in dd/mm/yyyy hh:mm:ss format, with a time-zone field expressed as +/-hhmm from GMT. For example: 02/Jan/1999:13:08:21 -0700
hostName	The name of the host machine on which the server is running: for example, showshoe. Note: If there is more than one instance of Messaging Server on the host, you can use the process ID (pid) to separate logged events of one instance from another.
processName	The name of the process that generated the event: for example, cgi_store.
pid	The process ID of the process that generated the event: for example, 18753.
category	The category that the event belongs to: for example, General (see Table 13-3 on page 431).
logLevel	The level of logging that the event represents: for example, Notice (see Table 13-2 on page 430).
eventMessage	An event-specific explanatory message that may be of any length: for example, Log created (894305624).

Here are three examples of logged events as viewed using iPlanet Console:

02/May/1998:17:37:32 -0700 showshoe cgi_store[18753]:
General Notice:
  Log created (894155852)

04/May/1998:11:07:44 -0400 xyzmail cgi_service[343]: General Error:
  function=getserverhello|port=2500|error=failed to connect

03/Dec/1998:06:54:32 +0200 SiroePost imapd[232]: Account Notice:
  close [127.0.0.1] [unauthenticated] 1998/12/3 6:54:32
  0:00:00 0 115 0

IMAP and POP event entries may end with three numbers. The example above has
0 115 0. The first number is bytes sent by client, the second number is the bytes sent by the server, and third number is mailboxes selected (always 1 for POP).

When viewing a log file in the Log Viewer window, you can limit the events displayed by searching for any specific component in an event, such as a specific logging level or category, or a specific process ID. For more information, see Searching and Viewing Logs.

The event message of each log entry is in a format specific to the type of event being logged: that is, each service defines what content appears in any of its event messages. Many event messages are simple and self-evident; others are more complex.

Defining and Setting Logging Options

You can define the message store and administration service logging configurations that best serve your administration needs. This section discusses issues that may help you decide on the best configurations and policies, and it explains how to implement them.

Flexible Logging Architecture

The naming scheme for log files (service.sequenceNum.timeStamp) helps you to design a flexible log-rotation and backup policy. The fact that events for different services are written to different files makes it easier for you to isolate problems quickly. Also, because the sequence number in a filename is ever-increasing and the timestamp is always unique, later log files do not simply overwrite earlier ones after a limited set of sequence numbers is exhausted. Instead, older log files are overwritten or deleted only when the more flexible limits of age, number of files, or total storage are reached.

Messaging Server supports automatic rotation of log files, which simplifies administration and facilitates backups. You are not required to manually retire the current log file and create a new one to hold subsequent logged events. You can back up all but the current log file in a directory at any time, without stopping the server or manually notifying the server to start a new log file.

In setting up your logging policies, you can set options (for each service) that control limits on total log storage, maximum number of log files, individual file size, maximum file age, and rate of log-file rotation.

Planning the Options You Want

Keep in mind that you must set several limits, more than one of which might cause the rotation or deletion of a log file. Whichever limit is reached first is the controlling one. For example, if your maximum log-file size is 3.5 MB, and you specify that a new log be created every day, you may actually get log files created faster than one per day if log data builds up faster than 3.5 MB every 24 hours. Then, if your maximum number of log files is 10 and your maximum age is 8 days, you may never reach the age limit on log files because the faster log rotation may mean that 10 files will have been created in less than 8 days.

The following default values, provided for Messaging Server administration logs, may be a reasonable starting point for planning:

Maximum number of log files in a directory: 10
Maximum log-file size: 2 MB
Total maximum size permitted for all log files: 20 MB
Minimum free disk space permitted: 5 MB
Log rollover time: 1 day
Maximum age before expiration: 7 days
Level of logging: Notice

You can see that this configuration assumes that server-administration log data is predicted to accumulate at about 2 MB per day, backups are weekly, and the total space allotted for storage of admin logs is at least 25 MB. (These settings may be insufficient if the logging level is more verbose.)

For POP, IMAP or HTTP logs, the same values might be a reasonable start. If all services have approximately the same log-storage requirements as the defaults shown here, you might expect to initially plan for about 150 MB of total log-storage capacity. (Note that this is meant only as a general indication of storage requirements; your actual requirements may be significantly different.)

To Set Logging Options

You can set options that control the message store logging configuration by using iPlanet Console or the command line.

The optimal settings for these options depend on the rate at which log data accumulates. It may take between 4,000 and 10,000 log entries to occupy 1 MB of storage. At the more verbose levels of logging (such as Notice), a moderately busy server may generate hundreds of megabytes of log data per week. Here is one approach you can follow:

• Set a level of logging that is consistent with your storage limits—that is, a level that you estimate will cause log-data accumulation at approximately the rate you used to estimate the storage limit.

• Define the log file size so that searching performance is not impacted. Also, coordinate it with your rotation schedule and your total storage limit. Given the rate at which log entries accumulate, you might set a maximum that is slightly larger than what you expect to accumulate by the time a rotation automatically occurs. And your maximum file size times your maximum number of files might be roughly equivalent to your total storage limit.

  For example, if your IMAP log rotation is daily, your expected accumulation of IMAP log data is 3 MB per day, and your total storage limit for IMAP logs is 25 MB, you might set a maximum IMAP log-file size of 3.5 MB. (In this example, you could still lose some log data if it accumulated so rapidly that all log files hit maximum size and the maximum number of log files were reached.)

• If server backups are weekly and you rotate IMAP log files daily, you might specify a maximum number of IMAP log files of about 10 (to account for faster rotation if the individual log-size limit is exceeded), and a maximum age of 7 or 8 days.

• Pick a total storage limit that is within your hardware capacity and that coordinates with the backup schedule you have planned for the server. Estimate the rate at which you anticipate that log data will accumulate, add a factor of safety, and define your total storage limit so that it is not exceeded over the period between server backups.

  For example, if you expect to accumulate an average of 3 MB of IMAP log-file data per day, and server backups are weekly, you might specify on the order of 25 - 30 MB as the storage limit for IMAP logs (assuming that your disk storage capacity is sufficient).

• For safety, pick a minimum amount of free disk space that you will permit on the volume that holds the log files. That way, if factors other than log-file size cause the volume to fill up, old log files will be deleted before a failure occurs from attempting to write log data to a full disk.

Note that you can choose to send log information to the syslog facility instead of to the server-supplied log files. You can send log information to syslog by setting the syslogfacility option as follows:

configutil -o logfile.service.syslogfacility -v value

where service is admin, pop, imap, imta, or http and value is user, mail, daemon, local0 to local7, or none.

If the value is set, Messages are logged to the syslog facility corresponding to the set value and all the other log file service options are ignored. When the option is not set or the value is none, logging uses the Messaging Server log files.

Console. To set logging options using iPlanet Console:

1. Open the Messaging Server whose log file options you want to set.

2. Click the Configuration tab, open the Log Files folder in the left pane, and select the log files of a service (such as IMAP, HTTP, or Admin).

3. From the "Levels of detail" drop-down list, choose a logging level.

4. In the "Directory path for log files" field, enter the name of the directory to hold your log files.

5. In the "File size for each log" field, enter your maximum log-file size.

6. In the "Create new log every" field, enter a number for the log-rotation schedule.

7. In the "Number of logs per directory" and the "When a log is older than" fields, enter the maximum number of log files and a maximum age to coordinate with your backup schedule.

8. In the "When total log size exceeds" field, enter the total storage limit you want.

9. In the "When free disk space is less than" field, enter the minimum amount of free disk space you want to reserve.

Command Line. To set logging options at the command line, use the configutil command as shown in the following examples.

To set the logging level:

configutil -o logfile.service.loglevel -v level

where service is admin, pop, imap, imta, or http and loglevel is Nolog, Critical, Error, Warning, Notice, Information, or Debug.

To specify a directory path for log files:

configutil -o logfile.service.logdir -v dirpath

To specify a maximum file size for each log:

configutil -o logfile.service.maxlogfilesize -v size

where size specifies a number of bytes.

To specify a log rotation schedule:

configutil -o logfile.service.rollovertime -v number

where number specifies a number of seconds.

To specify a maximum number of log files per directory:

configutil -o logfile.service.maxlogfiles -v number

To specify a storage limit:

configutil -o logfile.service.maxlogsize -v number

where number specifies a number in bytes.

To specify the a minimum amount of free disk space you want to reserve:

configutil -o logfile.service.minfreediskspace -v number

where number specifies a number in bytes.

To specify an age for logs at which they will expire:

configutil -o logfile.service.expirytime -v number

where number specifies a number in seconds.

Searching and Viewing Logs

iPlanet Console provides a basic interface for viewing message store and administration log data. It allows for selecting individual log files and for performing flexible filtered searches of log entries within those files.

For a given service, log files are listed in chronological order. Once you have chosen a log file to search, you can narrow the search for individual events by specifying search parameters.

Search Parameters

These are the search parameters you can specify for viewing log data:

• A time period. You can specify the beginning and end of a specific time period to retrieve events from, or you can specify a number of days (before the present) to search. You might typically specify a range to look at logged events leading up to a server crash or other occurrence whose time you know of. Alternatively, you might specify a day range to look at only today's events in the current log file.

• A level of logging. You can specify the logging level (see Logging Levels). You might select a specific level to uncover a specific problem; for example, Critical to see why the server went down, or Error to locate failed protocol calls.

• A facility. You can specify the facility (see Categories of Logged Events). You might select a specific facility if you know the functional area that contains the problem; for example, Store if you believe a server crash involved a disk error, or Protocol if the problem lies in an IMAP protocol command error.

• A text search pattern. You can provide a text search pattern to further narrow the search. You can include any component of the event (see Log File Format) that can be expressed in a wildcard-type search, such as event time, process name, process ID, and any part of the event message (such as remote host name, function name, error number, and so on) that you know defines the event or events you want to retrieve.

  Your search pattern can include the following special and wildcard characters:

  * Any set of characters (example: *.com)
  ? Any single character (example: 199?)
  [nnn] Any character in the set nnn (example: [aeiou])
  [^nnn] Any character not in the set nnn (example: [^aeiou])
  [n-m] Any character in the range n-m (example: [A-Z])
  [^n-m] Any character not in the range n-m (example: [^0-9])
  \ Escape character: place before *, ?, [, or ] to use them as literals

Note: Searches are case-sensitive.

Examples of combining logging level and facility in viewing logs might include the following:

• Specifying Account facility (and Notice level) to display failed logins, which may be useful when investigating potential security breaches

• Specifying Network facility (and all logging levels) to investigate connection problems

• Specifying all facilities (and Critical logging level) to look for basic problems in the functioning of the server

To Specify a Search and Viewing Results

Follow these steps to search for logged events with specific characteristics belonging to a given service:

1. In iPlanet Console, open the Messaging Server whose log files you want to inspect.

2. Follow either of these steps to display the Log Files Content tab for a given logged service:
   • Click the Tasks tab, then click "View service logs", where service is the name of the logged service (such as "IMAP service" or "administration").

   • Click the Configuration tab, then open the Log Files folder in the left pane and select the log files of a service (such as IMAP or Admin). Then click the Content tab in the right pane.

3. The Content tab for that logged service is displayed.

4. In the Log filename field, select the log file you want to examine.

5. Click the View selected log button to open the Log Viewer window.

6. In the Log Viewer window, specify your desired search parameters (described in the previous section, "Search Parameters").

7. Click Update to perform the search and display the results in the Log entry field.

PART 3: Service Logs (MTA)

---

The MTA provides facilities for logging each message as it is enqueued and dequeued. It also provides dispatcher error and debugging output. Part 3 contains the following sections:

• "To Enable MTA Logging"

• "To Specify Additional MTA Logging Options"

• "MTA Log Entry Format"

• "Managing the MTA Log Files"

• "Examples of MTA Message Logging"

• "Dispatcher Debugging and Log Files"

You can control logging on a per-channel basis or you can specify that message activity on all channels be logged. In the initial configuration, logging is disabled on all channels.

Enabling logging causes the MTA to write an entry to a mail.log* file each time a message passes through an MTA channel. Such log entries can be useful if you wish to get statistics on how many messages are passing through the MTA (or through particular channels), or when investigating other questions such as whether and when a message was sent or delivered.

If you are only interested in gathering statistics on the number of messages passing through a few particular MTA channels, then you may wish to enable the logging channel keyword on just those MTA channels of main interest. Many sites prefer to enable logging on all MTA channels. In particular, if you are trying to track down problems, the first step in diagnosing some problems is to notice that messages are not going to the channel you expected or intended, and having logging enabled for all channels can help you investigate such problems.

---

Caution

If logging is enabled, mail.log steadily grows and, if left unchecked, consumes all available disk space. Monitor the size of this file and periodically delete unnecessary contents. You can also delete the entire file as another version will be created as needed.

---

To Enable MTA Logging

To enable logging for a particular channel, you add the logging keyword to the channel definition in the MTA configuration file, as shown in the following example:

channel-name keyword1 keyword2 logging

In addition, you can also set a number of configuration parameters such as directory path for log files, log levels, an so on. See "PART 2: Service Logs (Message Store, Administration Server, and MTA)".

If you wish to have all of your channels log message activity to the logging file, then simply add a defaults channel block to the start of the channel block section of your MTA configuration file. For example:

defaults logging

l defragment charset7 us-ascii charset8 iso-8859-01
siroe.com

The defaults channel would appear immediately after the first blank line in the MTA configuration file. It is important that a blank line appear before and after the line defaults logging.

Each message is logged as it is enqueued and dequeued. All log entries are made to the file mail.log_current in the MTA log directory: msg-instance/log/imta/mail.log_current.

The message return job, which runs every night around midnight, appends any existing mail.log_yesterday to the cumulative log file, mail.log, renames the current mail.log_current file to mail.log_yesterday, and then begins a new mail.log_current file. It also performs the analogous operations for any connection.log* files.

You can send MTA log messages to syslog (UNIX) or event log (Windows NT) by setting the LOG_MESSAGES_SYSLOG option to 1. 0 is the default and indicates that syslog (event log) logging is not performed.

To Specify Additional MTA Logging Options

In addition to the basic information always provided when logging is enabled, you can specify that additional, optional information fields be included by setting various LOG_* MTA options in the MTA Option file. For complete details about the Option file, see the Messaging Server Reference Manual.

• LOG_MESSAGE_ID. This option allows correlation of which entries relate to which message.

• LOG_FILENAME. This option makes it easier to immediately spot how many times delivery of a particular message file has been retried, and can be useful in understanding when the MTA does or does not split a message to multiple recipients into separate message file copies on disk.

• LOG_CONNECTION. This option causes the MTA to log TCP/IP connections, as well as message traffic. The connection log entries are written to the mail.log* files by default, or may optionally be written to connection.log* files; see SEPARATE_CONNECTION_LOG option.

• SEPARATE_CONNECTION_LOG. This option may be used to specify that connection log entries instead be written to connection.log files.

• LOG_PROCESS. When used in conjunction with LOG_CONNECTION, this option allows correlation by process id of which connection entries correspond to which message entries.

• LOG_USERNAME. This option controls whether or not the user name associated with a process that enqueues mail is saved in the mail.log file. For SMTP submissions where SASL (SMTP AUTH) is used, the user name field will be the authenticated user name (prefixed with an asterisk character).

MTA Log Entry Format

The MTA log file is written as ASCII text. By default, each log file entry contains eight or nine fields as shown in Figure 13-1.

Figure 13-1    MTA Log Entry Format

19-Jan-1998 19:16:57.64 l tcp_local E 1 adam@sesta.com  rfc822;marlowe@siroe.com marlowe@siroe.com

The log entry shows:

1. The date and time the entry was made.

2. The channel name for the source channel (in the example, l).

3. The channel name for the destination channel (in the example, tcp_local). (For SMTP channels, when LOG_CONNECTION is enabled, a plus, +, indicates inbound to the SMTP server; a minus, -, indicates outbound via the SMTP client.)

4. The type of entry (E); see Table 13-6.

5. The size of the message (1). This is expressed in kilobytes by default, although this default can be changed by using the BLOCK_SIZE keyword in the MTA option file.

6. The envelope From: address (adam@sesta.com). Note that for messages with an empty envelope From: address, such as notification messages, this field will be blank.

7. The original form of the envelope To: address (marlowe@siroe.com).

8. The active (current) form of the envelope To: address (marlowe@siroe.com).

9. The delivery status (SMTP channels only).

Table 13-6 describes the logging entry codes.

Table 13-6    Logging Entry Codes

Entry	Description
D	Successful dequeue
DA	Successful dequeue with SASL (authentication)
DS	Successful dequeue with TLS (security)
DSA	Successful dequeue with TLS and SASL (security and authentication)
E	Enqueue
EA	Successful enqueue with SASL (authentication)
ES	Successful enqueue with TLS (security)
ESA	Successful enqueue with TLS and SASL (security and authentication)
J	Rejection of attempted enqueue (rejection by slave channel program)
Q	Temporary failure to dequeue
R	Recipient address rejected on attempted dequeue (rejection by master channel program), or generation of a failure/bounce message
W	Warning message generated regarding a not-yet-delivered message
Z	Some successful recipients, but this recipient was temporarily unsuccessful; the original message file of all recipients was dequeued, and in its place a new message file for this and other unsuccessful recipients will be immediately enqueued
SMTP channels' LOG_CONNECTION + or - entries
C	Connection closed
O	Connection opened
X	Connection rejected
Y	Connection attempt failed before being established
I	ETRN command received

With LOG_CONNECTION, LOG_FILENAME, LOG_MESSAGE_ID, LOG_NOTARY, LOG_PROCESS, and LOG_USERNAME all enabled, the format becomes as shown in Figure 13-2. (The sample log entry line has been wrapped for typographic reasons; the actual log entry would appear on one physical line.)

Figure 13-2    Log Format with Additional Fields

19-Jan-1998 13:13:27.10 HOSTA 2e2d.2.1 tcp_local l  E 1 service@siroe.com rfc822;adam@sesta.com  adam 276 /imta/queue/l/ZZ01IWFY9ELGWM00094D.00  <01IWFVYLGTS499EC9Y@siroe.com> inetmail  siroe.com (siroe.com [192.160.253.66])

Where the additional fields, beyond those already discussed above, are:

1. The name of the node on which the channel process is running (in the example, HOSTA).

2. The process id (expressed in hexadecimal), followed by a period (dot) character and a count. If this had been a multithreaded channel entry (e.g., a tcp_* channel entry), there would also be a thread id present between the process id and the count. In the example, the process id is 2e2d.2.1.

3. The NOTARY (delivery receipt request) flags for the message, expressed as an integer (in the example, 276).

4. The file name in the MTA queue area (in the example, /imta/queue/l/ZZ01IWFY9ELGWM00094D.00).

5. The message id (in the example, <01IWFVYLGTS499EC9Y@siroe.com>).

6. The name of the executing process (in the example, inetmail). On UNIX, for dispatcher processes such as the SMTP server, this will usually be inetmail (unless SASL was used).

7. The connection information (in the example, siroe.com (siroe.com [192.160.253.66]). The connection information consists of the sending system or channel name, such as the name presented by the sending system on the HELO/EHLO line (for incoming SMTP messages), or the enqueuing channel's official host name (for other sorts of channels). In the case of TCP/IP channels, the sending system's "real" name, that is, the symbolic name as reported by a DNS reverse lookup and/or the IP address, can also be reported within parentheses as controlled by the ident* channel keywords; see IDENT Lookups. This sample assumes use of one of these keywords, for instance us of the default identnone keyword, that selects display of both the name found from the DNS and IP address.

Managing the MTA Log Files

The message return job, which runs every night around midnight, appends any existing mail.log_yesterday to the cumulative log file, mail.log, renames the current mail.log_current file to mail.log_yesterday, and then begins a new mail.log_current file. It also performs the analogous operations for any connection.log* files.

The MTA performs automatic rollovers to maintain the current file, but you must manage the cumulative mail.log file by determining policies for tasks such as backing up the file, truncating the file, deleting the file, and so on.

When considering how to manage the log files, note that the MTA periodic return job will execute a site-supplied server-instance/imta/bin/daily_cleanup procedure, if one exists. Thus some sites might choose to supply their own cleanup procedure that, for instance, renames the old mail.log file once a week (or once a month), and so on.

Examples of MTA Message Logging

The exact field format and list of fields logged in the MTA message files will vary according to exactly what logging options you set. This section will show a few examples of interpreting typical sorts of log entries. For a description of additional, optional fields, see To Specify Additional MTA Logging Options.

---

Note	For typographic reasons, log file entries will be shown folded onto multiple lines—actual log file entries are one line per entry.

---

When reviewing a log file, keep in mind that on a typical system many messages are being handled at once. Typically, the entries relating to a particular message will be interspersed among entries relating to other messages being processed during that same time. The basic logging information is suitable for gathering a sense of the overall numbers of messages moving through the MTA.

If you wish to correlate particular entries relating to the same message to the same recipient(s), you will probably want to enable LOG_MESSAGE_ID. If you wish to correlate particular messages with particular files in the MTA queue area, or to see from the entries how many times a particular not-yet-successfully-dequeued message has had delivery attempted, you will probably want to enable LOG_FILENAME. For SMTP messages (handled via a TCP/IP channel), if you want to correlate TCP connections to and from remote systems with the messages sent, you will probably want to enable LOG_PROCESS and some level of LOG_CONNECTION.

Figure 13-3 show a fairly basic example of the sorts of log entries one might see if a local user sends a message out an outgoing TCP/IP channel, for example, to the Internet. In this example, LOG_CONNECTION is enabled. The lines marked with (1) and (2) are one entry—they would appear on one physical line in an actual log file. Similarly, the lines marked with (3) - (7) are one entry and would appear on one physical line.

Figure 13-3    Logging: A Local User Sends An Outgoing Message

19-Jan-1998 19:16:57.64 l tcp_local E 1 (1)  adam@sesta.com rfc822;marlowe@siroe.com marlowe@siroe.com (2) 19-Jan-1998 19:17:01.16 tcp_local D 1 (3)  adam@sesta.com rfc822;marlowe@siroe.com marlowe@siroe.com (4)  dns;thor.siroe.com  (TCP|206.184.139.12|2788|192.160.253.66|25) (5)  (THOR.SIROE.COM -- Server ESMTP [iMS V5.0 #8694]) (6)  smtp;250 2.1.5 marlowe@siroe.com and options OK. (7)

1. This line shows the date and time of an enqueue (E) from the l channel to the tcp_local channel of a one (1) block message.

2. This is part of the same physical line of the log file as (1), presented here as a separate line for typographical convenience. It shows the envelope From: address, in this case adam@sesta.com, and the original version and current version of the envelope To: address, in this case marlowe@siroe.com.

3. This shows the date and time of a dequeue (D) from the tcp_local channel of a one (1) block message—that is, a successful send by the tcp_local channel to some remote SMTP server.

4. This shows the envelope From: address, the original envelope To: address, and the current form of the envelope To: address.

5. This shows that the actual system to which the connection was made is named thor.siroe.com in the DNS, that the local sending system has IP address 206.184.139.12 and is sending from port 2788, that the remote destination system has IP address 192.160.253.66 and the connection port on the remote destination system is port 25.

6. This shows the SMTP banner line of the remote SMTP server.

7. This shows the SMTP status code returned for this address; 250 is the basic SMTP success code and in addition, this remote SMTP server responds with extended SMTP status codes and some additional text.

Figure 13-4 shows a logging entry similar to that shown in Figure 13-3, but with the additional information logged by setting LOG_FILENAME=1 and LOG_MESSAGE_ID=1 showing the filename and message-id; see (1) and (2). The message-id in particular can be used to correlate which entries relate to which message.

Figure 13-4    Logging: Including Optional Logging Fields

19-Jan-1998 19:16:57.64 l tcp_local E 1  adam@sesta.com rfc822;marlowe@siroe.com marlowe@siroe.com  /imta/queue/tcp_local/ZZ01ISKLSKLZLI90N15M.00    <01ISKLSKC2QC90N15M@sesta.com> (1) 19-Jan-1998 19:17:01.16 tcp_local D 1  adam@sesta.com rfc822;marlowe@siroe.com marlowe@siroe.com  /imta/queue/tcp_local/Z01ISKLSKLZLI90N15M.00    <01ISKLSKC2QC90N15M@sesta.com> (2)  dns;thor.siroe.com (TCP|206.184.139.12|2788|192.160.253.66|25)  (THOR.SIROE.COM -- Server ESMTP [iMS V5.0 #8694])  smtp;250 2.1.5 marlowe@siroe.com and options OK.

Figure 13-5 illustrates sending to multiple recipients with LOG_FILENAME=1, LOG_MESSAGE_ID=1, and LOG_CONNECTION=1 enabled. Here user adam@sesta.com has sent to the MTA mailing list test-list@sesta.com, which expanded to bob@sesta.com, carol@varrius.com, and david@varrius.com. Note that the original envelope To: address is test-list@sesta.com for each recipient, though the current envelope To: address is each respective address. Note how the message-id is the same throughout, though two separate files (one for the l channel and one going out the tcp_local channel) are involved.

Figure 13-5    Logging: Sending to a List

19-Jan-1998 20:01:44.10 l l E 1  adam@sesta.com rfc822;test-list@sesta.com bob  imta/queue/l/ZZ01ISKND3DE1K90N15M.00  <01ISKND2H8MS90N15M@sesta.com> 19-Jan-1998 20:01:44.81 l tcp_local E 1  adam@sesta.com rfc822;test-list@sesta.com carol@varrius.com  imta/queue/tcp_local/ZZ01ISKND2WS1I90N15M.00   <01ISKND2H8MS90N15M@sesta.com> 19-Jan-1998 20:01:44.81 l tcp_local E 1  adam@sesta.com rfc822;test-list@sesta.com david@varrius.com  imta/queue/tcp_local/ZZ01ISKND2WS1I90N15M.00  <01ISKND2H8MS90N15M@sesta.com> 19-Jan-1998 20:01:50.69 l D 1  adam@sesta.com rfc822;test-list@sesta.com bob  imta/queue/l/ZZ01ISKND3DE1K90N15M.00  <01ISKND2H8MS90N15M@sesta.com> 19-Jan-1998 20:01:57.36 tcp_local D 1  adam@sesta.com rfc822;test-list@sesta.com carol@varrius.com  imta/queue/tcp_local/ZZ01ISKND2WS1I90N15M.00  <01ISKND2H8MS90N15M@sesta.com>  dns;gw.varrius.com (TCP|206.184.139.12|2788|192.160.253.66|25)  (gw.varrius.com -- SMTP Sendmail)  smtp;250 OK. 19-Jan-1998 20:02:06.14 tcp_local D 1  adam@sesta.com rfc822;test-list@sesta.com david@varrius.com  imta/queue/tcp_local/ZZ01ISKND2WS1I90N15M.00  <01ISKND2H8MS90N15M@sesta.com>  dns;gw.varrius.com (TCP|206.184.139.12|2788|192.160.253.66|25)  (gw.varrius.com -- SMTP Sendmail)  smtp;250 OK.

Figure 13-6 illustrates an attempt to send to a non-existent domain (here very.bogus.com); that is, sending to a domain name that is not noticed as non-existent by the MTA's rewrite rules and that the MTA matches to an outgoing TCP/IP channel. This example assumes the MTA option settings of LOG_FILENAME=1 and LOG_MESSAGE_ID=1.

When the TCP/IP channel runs and checks for the domain name in the DNS, the DNS returns an error that no such name exists. Note the "rejection" entry (R), as seen in (5), with the DNS returning an error that this is not a legal domain name, as seen in (6).

Because the address is rejected after the message has been submitted, the MTA generates a bounce message to the original sender. The MTA enqueues the new rejection message to the original sender (1), and sends a copy to the postmaster (4) before deleting the original outbound message (the R entry shown in (5)).

Notification messages, such as bounce messages, have an empty envelope From: address—as seen, for instance, in (2) and (8)—in which the envelope From: field is shown as an empty space. The initial enqueue of a bounce message generated by the MTA shows the message-id for the new notification message followed by the message-id for the original message (3). (Such information is not always available to the MTA, but when it is available to be logged, it allows correlation of the log entries corresponding to the outbound failed message with the log entries corresponding to the resulting notification message.) Such notification messages are enqueued to the process channel, which in turn enqueues them to an appropriate destination channel (7).

Figure 13-6    Logging: Sending to a Non-existent Domain

19-JAN-1998 20:49:04 l tcp_local E 1  adam@sesta.com rfc822;user@very.bogus.com user@very.bogus.com  imta/queue/tcp_local/ZZ01ISKP0S0LVQ94DU0K.00  <01ISKP0RYMAS94DU0K@SESTA.COM> 19-JAN-1998 20:49:33 tcp_local process E 1 (1)  rfc822;adam@sesta.com adam@sesta.com (2)  imta/queue/process/ZZ01ISKP0S0LVQ94DTZB.00  <01ISKP22MW8894DTAS@SESTA.COM>,<01ISKP0RYMAS94DU0K@SESTA.COM> (3) 19-JAN-1998 20:49:33 tcp_local process E 1 (4)  rfc822;postmaster@sesta.com postmaster@sesta.com  imta/queue/process/ZZ01ISKP0S0LVQ94DTZB.00  <01ISKP22MW8894DTAS@SESTA.COM>,<01ISKP0RYMAS94DU0K@SESTA.COM> 19-JAN-1998 20:50:07 tcp_local R 1 (5)  adam@sesta.com rfc822;user@very.bogus.com user@very.bogus.com  imta/queue/tcp_local/ZZ01ISKP0S0LVQ94DU0K.00  <01ISKP0RYMAS94DU0K@SESTA.COM>  Illegal host/domain name found (6) 19-JAN-1998 20:50:08 process l E 3 (7)  rfc822;adam@sesta.com adam (8)  imta/queue/l/ZZ01ISKP23BUQS94DTYL.00  <01ISKP22MW8894DTAS@SESTA.COM> 19-JAN-1998 20:50:08 process l E 3  rfc822;postmaster@sesta.com postmaster  imta/queue/l/ZZ01ISKP23BUQS94DTYL.00  <01ISKP22MW8894DTAS@SESTA.COM> 19-JAN-1998 20:50:12 l D 3  rfc822;adam@sesta.com adam  imta/queue/l/ZZ01ISKP23BUQS94DTYL.00  <01ISKP22MW8894DTAS@SESTA.COM> 19-JAN-1998 20:50:12 l D 3  rfc822;postmaster@sesta.com postmaster  imta/queue/l/ZZ01ISKP23BUQS94DTYL.00  <01ISKP22MW8894DTAS@SIROE.COM>

Figure 13-7 illustrates an attempt to send to a bad address on a remote system. This example assumes MTA option settings of LOG_FILENAME=1 and LOG_MESSAGE_ID=1, and channel option settings of LOG_BANNER=1 and LOG_TRANSPORTINFO=1. Note the rejection entry (R), seen in (1). But in contrast to the rejection entry in Figure 13-6, note that the rejection entry here shows that a connection to a remote system was made, and shows the SMTP error code issued by the remote SMTP server, (2) and (3). The inclusion of the information shown in (2) is due to setting the channel options LOG_BANNER=1 and LOG_TRANSPORTINFO=1.

Figure 13-7    Logging: Sending to a Non-existent Remote User

20-JAN-1998 13:11:05 l tcp_local E 1  adam@sesta.com rfc822;nonesuch@siroe.com nonesuch@siroe.com  imta/queue/tcp_local/ZZ01ISLNBB1JOE94DUWH.00  <01ISLNBAWV3094DUWH@sesta.com> 20-JAN-1998 13:11:08 tcp_local process E 1  rfc822;adam@sesta.com adam@sesta.com  imta/queue/process/ZZ01ISLNBB1JOE94DSGB.00  <01ISLNBFKIDS94DUJ8@sesta.com>,<01ISLNBAWV3094DUWH@sesta.com> 20-JAN-1998 13:11:08 tcp_local process E 1  rfc822;postmaster@sesta.com postmaster@sesta.com  imta/queue/process/ZZ01ISLNBB1JOE94DSGB.00  <01ISLNBFKIDS94DUJ8@sesta.com>,<01ISLNBAWV3094DUWH@sesta.com> 20-JAN-1998 13:11:11 tcp_local R 1  (1)  adam@sesta.com rfc822;nonesuch@siroe.com nonesuch@siroe.com  imta/queue/tcp_local/ZZ01ISLNBB1JOE94DUWH.00   <01ISLNBAWV3094DUWH@sesta.com>  dns;thor.siroe.com  (TCP|206.184.139.12|2788|192.160.253.66|25)         (2)  (THOR.SIROE.COM -- Server ESMTP [iMS V5.0 #8694])  smtp; 553 unknown or illegal user: nonesuch@siroe.com  (3) 20-JAN-1998 13:11:12 process l E 3  rfc822;adam@sesta.com adam  imta/queue/l/ZZ01ISLNBGND1094DQDP.00  <01ISLNBFKIDS94DUJ8@sesta.com> 20-JAN-1998 13:11:12 process l E 3  rfc822;postmaster@sesta.com postmaster  imta/queue/l/ZZ01ISLNBGND1094DQDP.00  <01ISLNBFKIDS94DUJ8@sesta.com> 20-JAN-1998 13:11:13 l D 3  rfc822;adam@sesta.com adam@sesta.com  imta/queue/l/ZZ01ISLNBGND1094DQDP.00  <01ISLNBFKIDS94DUJ8@sesta.com> 20-JAN-1998 13:11:13 l D 3  rfc822;postmaster@sesta.com postmaster@sesta.com  imta/queue/l/ZZ01ISLNBGND1094DQDP.00  <01ISLNBFKIDS94DUJ8@sesta.com>

Figure 13-8 illustrates the sort of log file entry resulting when the MTA rejects a remote side's attempt to submit a message. (This example assumes that no optional LOG_* options are enabled, so only the basic fields are logged in the entry. Note that enabling the LOG_CONNECTION option, in particular, would result in additional informative fields in such J entries.) In this case, the example is for an MTA that has set up SMTP relay blocking (see Configuring SMTP Relay Blocking) with an ORIG_SEND_ACCESS mapping including:

ORIG_SEND_ACCESS

! ...numerous entries omitted...
!
   tcp_local|*|tcp_local|* $NRelaying$ not$ permitted

and where alan@very.bogus.com is not an internal address. Hence the attempt of the remote user harold@varrius.com to relay through the MTA system to the remote user alan@very.bogus.com is rejected.

Figure 13-8    Logging: Rejecting a Remote Side's Attempt to Submit a Message

28-May-1998 12:02:23 tcp_local J 0     (1)  harold@varrius.com rfc822; alan@very.bogus.com       (2)  550 5.7.1 Relaying not permitted: alan@very.bogus.com (3)

1. This log shows the date and time the MTA rejects a remote side's attempt to submit a message. The rejection is indicated by a J record. (Cases where an MTA channel is attempting to send a message which is rejected is indicated by R records, as shown in Figure 13-6 and Figure 13-7).

2. The attempted envelope From: and To: addresses are shown. In this case, no original envelope To: information was available so that field is empty.

3. The entry includes the SMTP error message the MTA issued to the remote (attempted sender) side.

Figure 13-9 illustrates the sort of log file entries resulting when a message cannot be delivered upon the first attempt, so the MTA attempts to send the message several times. This example assumes option settings of LOG_FILENAME=1 and LOG_MESSAGE_ID=1.

Figure 13-9    Logging: Multiple Delivery Attempts

15-Jan-1998 10:31:05.18 tcp_internal tcp_local E 3 (1)  adam@hosta.sesta.com rfc822;user@some.org user@some.org  imta/queue/tcp_local/ZZ01IS3D2ZP7FQ9UN54R.00   <01IRUD7SVA3Q9UN2D4@sesta.com> 15-Jan-1998 10:31:10.37 tcp_local Q 3 (2)  adam@hosta.sesta.com rfc822;user@some.org user@some.org  imta/queue/tcp_local/ZZ01IS3D2ZP7FQ9UN54R.00         (3)  <01IRUD7SVA3Q9UN2D4@sesta.com>  TCP active open: Failed connect() Error: no route to host (4)  ...several hours worth of entries... 15-Jan-1998 12:45:39.48 tcp_local Q 3 (5)  adam@hosta.sesta.com rfc822;user@some.org user@some.org  imta/queue/tcp_local/ZY01IS3D2ZP7FQ9UN54R.00         (6)  <01IRUD7SVA3Q9UN2D4@sesta.com>  TCP active open: Failed connect() Error: no route to host  ...several hours worth of entries... 15-Jan-1998 16:45:24.72 tcp_local Q 3  adam@hosta.sesta.com rfc822;user@some.org user@some.org  imta/queue/tcp_local/ZX01IS67NY4RRK9UN7GP.00         (7)  <01IRUD7SVA3Q9UN2D4@sesta.com>  TCP active open: Failed connect() Error: connection refused (8)  ...several hours worth of entries... 15-Jan-1998 20:45:51.55 tcp_local D 3 (9)  adam@hosta.sesta.com rfc822;user@some.org user@some.org  imta/queue/tcp_local/ZX01IS67NY4RRK9UN7GP.00  <01IRUD7SVA3Q9UN2D4@sesta.com>  dns;host.some.org (TCP|206.184.139.12|2788|192.1.1.1|25)  (All set, fire away)  smtp; 250 Ok

1. The message comes in the tcp_internal channel—perhaps from a POP or IMAP client, or perhaps from another host within the organization using the MTA as an SMTP relay; the MTA enqueues it to the outgoing tcp_local channel.

2. The first delivery attempt fails, as indicated by the Q entry.

3. That this is a first delivery attempt can be seen from the ZZ* filename.

4. This delivery attempt failed when the TCP/IP package could not find a route to the remote side. As opposed to Figure 13-6, the DNS did not object to the destination domain name, some.org; rather, the "no route to host" error indicates that there is some network problem between the sending and receiving side.

5. The next time the MTA periodic job runs it reattempts delivery, again unsuccessfully.

6. The file name is now ZY*, indicating that this is a second attempt.

7. The file name is ZX* for this third unsuccessful attempt.

8. The next time the periodic job reattempts delivery the delivery fails, though this time the TCP/IP package is not complaining that it cannot get through to the remote SMTP server, but rather the remote SMTP server is not accepting connections. (Perhaps the remote side fixed their network problem, but has not yet brought their SMTP server back up—or their SMTP server is swamped handling other messages and hence was not accepting connections at the moment the MTA tried to connect.)

9. Finally the message is dequeued.

Figure 13-10 illustrates the case of a message routed through the conversion channel. The site is assumed to have a CONVERSIONS mapping table such as:

CONVERSIONS

  IN-CHAN=tcp_local;OUT-CHAN=l;CONVERT Yes

This example assumes option settings of LOG_FILENAME=1 and LOG_MESSAGE_ID=1.

Figure 13-10    Logging: Incoming SMTP Message Routed Through the Conversion Channel

04-Feb-1998 00:06:26.72 tcp_local conversion E 9 (1)  amy@siroe.edu rfc822;bert@sesta.com bert@sesta.com  imta/queue/conversion/ZZ01IT5UAMZ4QW98518O.00  <01IT5UALL14498518O@siroe.edu> 04-Feb-1998 00:06:29.06 conversion l E 9 (2)  amy@siroe.edu rfc822;bert@sesta.com bert  imta/queue/l/ZZ01IT5UAOXLDW98509E.00  <01IT5STUMUFO984Z8L@siroe.edu> 04-Feb-1998 00:06:29.31 conversion D 9 (3)  amy@siroe.edu rfc822;bert@sesta.com bert  imta/queue/conversion/ZZ01IT5UAMZ4QW98518O.00  <01IT5UALL14498518O@siroe.edu> 04-Feb-1998 00:06:32.62 l D 9 (4)  amy@siroe.edu rfc822;bert@siroe.com bert  imta/queue/l/ZZ01IT5UAOXLDW98509E.00  <01IT5STUMUFO984Z8L@siroe.edu>

1. The message from external user amy@siroe.edu comes in addressed to the l channel recipient bert@sesta.com. The CONVERSIONS mapping entry, however, causes the message to be initially enqueued to the conversion channel (rather than directly to the l channel).

2. The conversion channel runs and enqueues the message to the l channel.

3. Then the conversion channel can dequeue the message (delete the old message file).

4. And finally the l channel dequeues (delivers) the message.

Figure 13-11 illustrates log output for an outgoing message when connection logging is enabled, via LOG_CONNECTION=3. LOG_PROCESS=1, LOG_MESSAGE_ID=1 and LOG_FILENAME=1 are also assumed in this example. The example shows the case of user adam@sesta.com sending the same message (note that the message ID is the same for each message copy) to three recipients, bobby@hosta.sesta.com, carl@hosta.sesta.com, and dave@hostb.sesta.com. This example assumes that the message is going out a tcp_local channel marked (as such channels usually are) with the single_sys channel keyword. Therefore, a separate message file on disk will be created for each set of recipients to a separate host name, as seen in (1), (2), and (3), where the bobby@hosta.sesta.com and carl@hosta.sesta.com recipients are stored in the same message file, but the dave@hostb.sesta.com recipient is stored in a different message file.

Figure 13-11    Logging: Outbound Connection Logging

19-Feb-1998 10:52:05.41 1e488.0 l tcp_local E 1

adam@sesta.com rfc822;bobby@hosta.sesta.com bobby@hosta.sesta.com

imta/queue/tcp_local/ZZ01ITRF7BO388000FCN.00  (1)   <01ITRF7BDHS6000FCN@SESTA.COM>

19-Feb-1998 10:52:05.41 1e488.0 l tcp_local E 1

adam@sesta.com rfc822;carl@hosta.sesta.com carl@hosta.sesta.com

imta/queue/tcp_local/ZZ01ITRF7BO388000FCN.00  (2)   <01ITRF7BDHS6000FCN@SESTA.COM>

19-Feb-1998 10:52:05.74 1e488.1 l tcp_local E 1

adam@sesta.com rfc822;dave@hostb.sesta.com dave@hostb.sesta.com

imta/queue/tcp_local/ZZ01ITRF7C11FU000FCN.00  (3)   <01ITRF7BDHS6000FCN@SESTA.COM>

19-Feb-1998 10:52:10.79 1f625.2.0 tcp_local - O (4)

TCP|206.184.139.12|5900|206.184.139.66|25  SMTP/hostb.sesta.com/mailhub.sesta.com         (5)

19-Feb-1998 10:52:10.87 1f625.3.0 tcp_local - O (6)

TCP|206.184.139.12|5901|206.184.139.70|25  SMTP/hosta.sesta.com/hosta.sesta.com          (7)

19-Feb-1998 10:52:12.28 1f625.3.1 tcp_local D 1

adam@sesta.com rfc822;bobby@hosta.sesta.com bobby@hosta.sesta.com

imta/queue/tcp_local/ZZ01ITRF7BO388000FCN.00   <01ITRF7BDHS6000FCN@SESTA.COM>

hosta.sesta.com dns;hosta.sesta.com          (8)

(TCP|206.184.139.12|5901|206.184.139.70|25)

(hosta.sesta.com -- Server ESMTP [iMS V5.0 #8790])

(TCP|206.184.139.12|5901|206.184.139.70|25)

smtp;250 2.1.5 bobby@hosta.sesta.com and options OK.

19-Feb-1998 10:52:12.28 1f625.3.1 tcp_local D 1

adam@sesta.com rfc822;carl@hosta.sesta.com carl@hosta.sesta.com

imta/queue/tcp_local/ZZ01ITRF7BO388000FCN.00   <01ITRF7BDHS6000FCN@SESTA.COM>

hosta.sesta.com dns;hosta.sesta.com

(TCP|206.184.139.12|5901|206.184.139.70|25)

(hosta.sesta.com -- Server ESMTP [iMS V5.0 #8790])

(TCP|206.184.139.12|5901|206.184.139.70|25)

smtp;250 2.1.5 carl@hosta.sesta.com and options OK.

19-Feb-1998 10:52:12.40 1f625.3.2 tcp_local - C (9)

TCP|206.184.139.12|5901|206.184.139.70|25

SMTP/hosta.sesta.com/hosta.sesta.com

19-Feb-1998 10:52:13.01 1f625.2.1 tcp_local D 1

adam@sesta.com rfc822;dave@hostb.sesta.com dave@hostb.sesta.com

imta/queue/tcp_local/ZZ01ITRF7C11FU000FCN.00   <01ITRF7BDHS6000FCN@SESTA.COM>

mailhub.sesta.com dns;mailhub.sesta.com

(TCP|206.184.139.12|5900|206.184.139.66|25)

(MAILHUB.SESTA.COM -- Server ESMTP [iMS V5.0 #8694])

(TCP|206.184.139.12|5900|206.184.139.66|25)

smtp;250 2.1.5 dave@hostb.sesta.com and options OK.

19-Feb-1998 10:52:13.05 1f625.2.2 tcp_local - C (10)

TCP|206.184.139.12|5900|206.184.139.66|25

SMTP/hostb.sesta.com/mailhub.sesta.com

1. The message is enqueued to the first recipient...

2. ....and to the second recipient...

3. ....and to the third recipient.

4. Having LOG_CONNECTION=3 set causes the MTA to write this entry. The minus, -, indicates that this entry refers to an outgoing connection. The O means that this entry corresponds to the opening of the connection. Also note that the process id here is the same, 1f625, since the same process is used for the multithreaded TCP/IP channel for these separate connection opens, though this open is being performed by thread 2 vs. thread 3.

5. As there are two separate remote systems to which to connect, the multithreaded SMTP client in separate threads opens up a connection to each—the first in this entry, and the second shown in 7. This part of the entry shows the sending and destination IP numbers and port numbers, and shows both the initial host name, and the host name found by doing a DNS lookup. In the SMTP/initial-host/dns-host clauses, note the display of both the initial host name, and that used after performing a DNS MX record lookup on the initial host name: mailhub.sesta.com is apparently an MX server for hostb.sesta.com.

6. The multithreaded SMTP client opens up a connection to the second system in a separate thread (though the same process).

7. As there are two separate remote systems to which to connect, the multithreaded SMTP client in separate threads opens up a connection to each—the second in this entry, and the first shown above in 5. This part of the entry shows the sending and destination IP numbers and port numbers, and shows both the initial host name, and the host name found by doing a DNS lookup. In this example, the system hosta.sesta.com apparently receives mail directly itself.

8. Besides resulting in specific connection entries, LOG_CONNECTION=3 also causes inclusion of connection related information in the regular message entries, as seen here for instance.

9. Having LOG_CONNECTION=3 causes the MTA to write this entry. After any messages are dequeued, (the bobby and carl messages in this example), the connection is closed, as indicated by the C in this entry.

10. Having LOG_CONNECTION=3 causes the MTA to write this entry. After any messages are dequeued, (the dave message in this example), the connection is closed, as indicated by the C in this entry.

Figure 13-12 illustrates log output for an incoming SMTP message when connection logging is enabled, via LOG_CONNECTION=3.

Figure 13-12    Logging: Inbound Connection Logging

19-Feb-1998 17:02:08.70 tcp_local    +            O   (1)  TCP|206.184.139.12|25|192.160.253.66|1244 SMTP       (2) 19-Feb-1998 17:02:26.65 tcp_local    l             E 1  service@siroe.com rfc822;adam@sesta.com adam  THOR.SIROE.COM (THOR.SIROE.COM [192.160.253.66])      (3) 19-Feb-1998 17:02:27.05 tcp_local    +             C   (4)  TCP|206.184.139.12|25|192.160.253.66|1244 SMTP 19-Feb-1998 17:02:31.73 l                          D 1  service@siroe.com rfc822;adam@sesta.com adam

1. The remote system opens a connection. The O character indicates that this entry regards the opening of a connection; the + character indicates that this entry regards an incoming connection.

2. The IP numbers and ports for the connection are shown. In this entry, the receiving system (the system making the log file entry) has IP address 206.184.139.12 and the connection is being made to port 25; the sending system has IP address 192.160.253.66 and is sending from port 1244.

3. In the entry for the enqueue of the message from the incoming TCP/IP channel (tcp_local) to the l channel recipient, note that information beyond the default is included since LOG_CONNECTION=3 is enabled. Specifically, the name that the sending system claimed on its HELO or EHLO line, the sending system's name as found by a DNS reverse lookup on the connection IP number, and the sending system's IP address are all logged; see Chapter 8 "Configuring Channel Definitions," for a discussion of channel keywords affecting this behavior.

4. The inbound connection is closed. The C character indicates that this entry regards the closing of a connection; the + character indicates that this entry regards an incoming connection.

Dispatcher Debugging and Log Files

Dispatcher error and debugging output (if enabled) are written to the file dispatcher.log in the MTA log directory.

Debugging output may be enabled using the option DEBUG in the Dispatcher configuration file, or on a per-process level, using the IMTA_DISPATCHER_DEBUG environment variable (UNIX).

The DEBUG option or IMTA_DISPATCHER_DEBUG environment variable (UNIX) defines a 32-bit debug mask in hexadecimal. Enabling all debugging is done by setting the option to -1, or by defining the logical or environment variable system-wide to the value FFFFFFFF. The actual meaning of each bit is described in Table 13-7.

Table 13-7    Dispatcher Debugging Bits 

Bit	Hexadecimal value	Decimal value	Usage
0	x 00001	1	Basic Service Dispatcher main module debugging.
1	x 00002	2	Extra Service Dispatcher main module debugging.
2	x 00004	4	Service Dispatcher configuration file logging.
3	x 00008	8	Basic Service Dispatcher miscellaneous debugging.
4	x 00010	16	Basic service debugging.
5	x 00020	32	Extra service debugging.
6	x 00040	64	Process related service debugging.
7	x 00080	128	Not used.
8	x 00100	256	Basic Service Dispatcher and process communication debugging.
9	x 00200	512	Extra Service Dispatcher and process communication debugging.
10	x 00400	1024	Packet level communication debugging.
11	x 00800	2048	Not used.
12	x 01000	4096	Basic Worker Process debugging.
13	x 02000	8192	Extra Worker Process debugging.
14	x 04000	16384	Additional Worker Process debugging, particularly connection hand-offs
15	x 08000	32768	Not used.
16	x 10000	65536	Basic Worker Process to Service Dispatcher I/O debugging.
17	x 20000	131072	Extra Worker Process to Service Dispatcher I/O debugging.
20	x 100000	1048576	Basic statistics debugging.
21	x 200000	2097152	Extra statistics debugging.
24	x 1000000	16777216	Log PORT_ACCESS denials to the dispatcher.log file.

System Parameters on Solaris

The system's heap size (datasize) must be enough to accommodate the Dispatcher's thread stack usage. For each Dispatcher service compute STACKSIZE*MAX_CONNS, and then add up the values computed for each service. The system's heap size needs to be at least twice this number.

The Dispatcher services offered in the Dispatcher configuration file affects requirements for various system parameters.

To display the heap size (that is, default datasize), use the csh command:

# limit

or the ksh command

# ulimit -a

or the utility

# sysdef