MTA transaction log entry format

From Messaging Server Technical Reference Wiki
Jump to: navigation, search


The format of message transaction log entries and connection transaction log entries is subject to change. By default, message transaction log entries and connection transaction log entries all appear in the same message log files (mail.log* files); however, if the MTA option separate_connection_log=1 is set, then the connection transaction log entries will instead appear in the connection transaction log files (connection.log* files).

Currently, by default, each message transaction log entry contains eight or nine fields, e.g.,


19-Jan-1998 19:16:57.64 tcp_intranet tcp_local    E 1 adam@domain.com rfc822;mark@innosoft.com mark@innosoft.com 
 
            (1)         (2)              (3)      (4)(5)    (6)         (7)                        (8)       (9)

These fields are:

  1. The date and time when the entry was made.
  2. The channel name for the source channel.
  3. The channel name for the destination channel.
  4. The type of entry; see Message logging entry action type codes.
  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 MTA option. If message size is not an exact block_size multiple, then the size is rounded up to the next block for logging purposes. (Note that in "Q" records, the size is not necessarily the size of the message as a whole, but rather indicates the amount of message processed before the delivery attempt failed: in particular, the size field in a "Q" record may be 0 such as in cases where the MTA's SMTP client encounters a connection failure, or the size field may correspond to the full size of the message such as in cases where the MTA's SMTP client encounters message rejection after the final ".", or in cases such as a network disconnect part way through message transfer the size field will indicate roughly at what point in message transfer the disconnect occurred.)
  6. The envelope From address. 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. (Note that this is the ORCPT value, and hence follows ORCPT syntax; see RFC 3461. Also note that the semantics of ORCPT are neither "originally submitted address", nor "address originally given to this MTA", and hence ORCPT only sometimes corresponds to one or the other or both. For the "address originally given to this MTA", see instead the log_intermediate MTA option.)
  8. The active (current) form of the envelope To address.
  9. The delivery status (SMTP channels only).
Message logging entry action type codes
Type Modifiers Description
General
B E, P, A, S, U, B, C (New in MS 6.2) Unrecognized/invalid SMTP command. Logging limit set by MAX_B_ENTRIES TCP/IP channel-specific option.
D E, L, A, S, U, B, C Successful dequeue
E E, P, A, S, U, B, C, W, T Enqueue. An "E" or null modifier will be present to indicate whether the enqueue was with EHLO or HELO, respectively.
H E, P, A, S, U, B, C (New in MS 8.1) VRFY/EXPN command. Logging limit set by MAX_H_ENTRIES TCP/IP channel-specific option.
J E, P, A, S, U, B, C, W, T, R Rejection of attempted enqueue (rejection by slave channel program). Logging limit set by MAX_J_ENTRIES TCP/IP channel-specific option,
K E, L, S, U, B, C Recipient address rejected on attempted dequeue (rejection by master channel program) when the recipient has the NOTIFY=NEVER DSN flag set (so no bounce message will be generated regarding this rejection), or deletion of a timed-out NOTIFY=NEVER message by the return_job; compare with "R" records which are the same sort of rejection/time-out occurring, but where a new notification message is also generated regarding this failed message
P F, X, J, Y, D (New in MS 8.0) Request to generate a Delivery Status Notification. (Note that in some cases no actual DSN will end up being sent.) "P" records are only generated in cases where the error causing the DSN isn't recorded in any other log entry. The various cases where this happens are further detailed by the presence of a modifier character on the action. Currently the defined modifiers are:
  • F - address errors detected during alias or mailing list expansion operations (this includes bad RCPT TO addresses that are allowed because the acceptalladdresses channel option is in effect)
  • X - capture operations
  • J - journal operations
  • Y - Sieve syntax or evaluation errors
  • D - success delivery receipts
Q E, L, S, U, B, C Temporary failure to dequeue
R E, L, S, U, B, C Recipient address rejected on attempted dequeue (rejection by master channel program), or generation of a failure/bounce message; compare with "K" records, which are the same sort of rejection/time-out occurring, but where no notification message is generated and the original message is just deleted
V E, L, P, A, S, C (New in MS 6.2p2) An incoming SMTP transaction ended prematurely; frequently corresponds to an address verification operation by a remote SMTP client. The "C" modifier was not recorded on "V" records until circa MS 7.0u4
W   Warning message (generated by the return_job) regarding a not-yet-delivered message
Z E, L, P, A, S, U, B, C 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 reenqueued
LMTP server
J S, C Rejection by LMTP server of address or message. Logging limit set by MAX_J_ENTRIES TCP/IP channel-specific option, As of MS 7.0, J records are routinely generated for LMTP server rejections (whereas in previous versions only LMTP rejections at the envelope address stages would be recorded, while LMTP rejections after the DATA would not be recorded). Prior to MS 7.0u4, note that unlike SMTP and SMTP SUBMIT server "J" records, LMTP server "J" records did not include any modifier letters; new in MS 7.0u4, "S" (TLS used) and/or "C" (CHUNKING used) modifiers may be present.
S S, C (New in MS 7.0) LMTP deposit into the store; in prior versions indicated with the (somewhat misleading) D action code instead; the addition of "S" (TLS used) and/or "C" (CHUNKING used) modifiers is new in MS 7.0u4.
SMTP/LMTP modifiers
  E (New in MS 6.3) ESMTP (EHLO) used
  L (New in MS 6.3) LMTP (LHLO) used
    Absence of both "E" and "L" implies that HELO was used
  P (New in MS 7.0) POP-before-SMTP used (via the MMP)
  Q (New in 7.0) Pipelining used
  A Authentication (SMTP AUTH) successfully used
  S TLS (STARTTLS) successfully used
  U (New in MS 7.0) BURL used.
  B (New in MS 8.0) BINARYMIME used; see the binaryserver channel option.
  C (New in MS 6.3) CHUNKING used without BINARYMIME; see the chunking* channel options.
  8 (New in MS 8.0) UTF-8 message transfer (UTF8SMTP) successfully used
  W (New in MS 8.1.0.1) Lines longer than 1000 characters were found and wrapped
  T (New in MS 8.1.0.1) Lines longer than 1000 characters were found and truncated
  R (New in MS 8.1.0.1) Lines longer than 1000 characters were found, causing the message to be rejected

In addition to the default message transaction fields (shown above), the MTA may optionally be configured to log additional information to the message transaction log file; see the log_* MTA options described in Transaction logging MTA options. With log_connection, log_filename, log_envelope_id, log_message_id, log_node, log_notary, log_sensitivity, log_priority, log_process, and log_username all enabled, the format becomes as follows. (Note that the sample transaction log entry line has been wrapped for typographic reasons; the actual message transaction log entry would appear on one physical line.)


19-Jan-1998 13:13:27.10 hosta   2e2d.5.1 tcp_local   tcp_intranet E 1 service@innosoft.com  
           (1)           (10)     (11)     (2)        (3)        (4) (5)   (6)                

 rfc822;adam@domain.com adam 276 
 (7)                     (8) (12) 

 /opt/sun/comms/messaging64/data/queue/tcp_intranet/ZZi0D4d9f5mwC.00
          (13)                      

 <01IWFVYLGTS499EC9W@innosoft.com> <01IWFVYLGTS499EC9Y@innosoft.com> 
          (14)                     (15)  

 mailsrv innosoft.com (innosoft.com [192.160.253.66]) 0 3 
 (16)    (17)                                      (18) (19)  (9)

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

  • (10) (log_node) The name of the node on which the channel process is running.
  • (11) (log_process) The process id (expressed in hexadecimal), followed by a period (dot) character, if it is a multithreaded channel entry a process id and another period (dot), and finally a count.
  • (12) (log_notary) The NOTARY (delivery receipt request) flags for the message, expressed as an integer.
  • (13) (log_filename) The file name in the MTA queue area.
  • (14) (log_envelope_id) The envelope id.
  • (log_tracking new in MS 8.0 and not shown in the above example) Tracking ID.
  • (log_times new in MS 8.0 and not shown in the above example) Deferred delivery time and expiry time.
  • (15) (log_message_id) The message id.
  • (16) (log_username) The username of the executing process. Note that in the case of Dispatcher services such as the SMTP server, this will be the username of the user who most recently did a startup of the Dispatcher.
  • (log_auth new in MS 7.0.5 and not shown in the above example) The SMTP MAIL FROM's AUTH parameter value.
  • (17) (log_connection) The exact connection information shown varies according to whether a message is incoming (E record) or outgoing (e.g., D record), whether or not the channel is an SMTP (or LMTP) channel, and for SMTP/LMTP channels for incoming messages, the specific bits set for the log_connection MTA option. For incoming messages, 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 options. This sample assumes use of one of these options, for instance use of the default identnone channel option, that selects display of both the name found from the DNS and IP address. This example also assumes that log_connection=1 is set, but that higher bits of log_connection are not set. If bit 5 (value 32) of log_connection were set, then the incoming connection information for a message incoming over TCP/IP would also include the entire transport information string, TCP|MTA-IP|MTA-port|remote-IP|remote-port. If bit 6 (value 64) of log_connection were set, then the incoming connection information would also include the application information string, just SMTP for the case of incoming SMTP messages. For outgoing messages, e.g., D records, the connection information (due to log_connection's bit 0/value 1 being set) is present only for SMTP/LMTP channels, and in such cases consists of the remote host name and the remote name as found in the DNS, the transport information string (see above), and the remote SMTP banner line. And this information is included at the start of the SMTP diagnostic field.
  • (18) (log_sensitivity) The sensitivity for the message.
  • (log_mtpriority new in MS 8.0 and not shown in the above example) The SMTP MT-PRIORITY associated with the transaction.
  • (19) (log_priority) This effective processing priority for the message; 3 corresponds to "normal" priority. Note that the effective processing priority may not be the same as the message's Priority: header value (if any); for instance, the *blocklimit channel options can cause lowering of effective message processing priority.
  • (log_intermediate not shown in the above example) The intermediate form of the recipient address.
  • (log_intermediate not shown in the above example) The original (RCPT TO) form of the recipient address.
  • (log_uid new in MS 8.0 and not shown in the above example) LDAP uid attribute for local users.
  • (log_mailbox_uid new in MS 7.0.5 and not shown in the above example) For messages delivered to the MS Message Store, the UID and UIDVALIDITY.
  • (log_futurerelease new in MS 8.0 and not shown in the above example) SMTP FUTURERELEASE value.
  • (log_filter not shown in the above example) The Sieve filter actions applying to the message, including effects from verdicts from spam/virus package "plug-ins".
  • (log_reason new in MS 6.3 and not shown in the above example) The reason field (due to setting log_reason=1). It would appear in a message transaction log entry corresponding to a message rejection (for instance, an "R" or "K" entry), appearing just before the SMTP delivery status (SMTP diagnostic) field.
  • (log_diagnostics not shown in the above example) The SMTP delivery status/SMTP diagnostic field (due to having the default of log_diagnostics=1 set)
  • (log_queue_time new in MS 6.3 and not shown in the above example) The "time in queue" field (due to setting log_queue_time=1).
  • (log_conversion_tag new in MS 7.0.5 and not shown in the above example) Any conversion tags on the message.
  • (log_imap_flags new in MS 7.0.5 and not shown in the above example) Any IMAP flags that have been set on the message by the MTA.
  • (log_delivery_flags new in MS 7.0.5 and not shown in the above example) Delivery flags.
  • (log_callout_delays new in MS 8.0 and not shown in the above example) Callout delay timer values.
  • (log_transactionlog new in MS 8.0 and not shown in the above example) String(s) logged due to the Sieve "transactionlog" action.

The maximum line length for message transaction records is 4096 characters.

Currently, each connection transaction log entry contains at least six fields, with the presence of up to five additional optional fields controlled by the MTA options log_node, log_process, log_message_id, log_username, and log_queue_time, e.g.,


04-Sep-2002 01:00:04.23 host.domain.com 1f625.d.0 tcp_local    +            O TCP|129.153.12.42|25|123.4.5.67|65228 SMTP 
04-Sep-2002 01:00:05.21 host.domain.com 1f625.d.3 tcp_local    +            C TCP|129.153.12.42|25|123.4.5.67|65228 SMTP/TLS-192-DES-CBC3-SHA 
04-Sep-2002 01:00:06.23 host.domain.com 1f627.3.0 tcp_local    -            O TCP|129.153.12.42|4303|123.45.6.7|25 SMTP/domain.com/mail.domain.com 
04-Sep-2002 01:00:06.49 host.domain.com 1f627.3.3 tcp_local    -            C TCP|129.153.12.42|4303|123.45.6.7|25 SMTP/domain.com/mail.domain.com/TLS-192-DES-CBC3-SHA 
 
        (1)              (2)                (3)      (4)      (5)          (6)   (7)                             (8)
  • (1) The date and time when the entry was made.
  • (2) [Optional---only present when log_node=1 is set.] (New in MS 6.3) The host name of the MTA system.
  • (3) [Optional---only present when log_process=1 is set.] The process id (expressed in hexadecimal), followed by a period (dot) character and then a thread id, followed by a period (dot) character and a count.
  • (4)The channel name for the source channel. In the case of "-" entries (outgoing messages), this is the name of the channel acting as SMTP client or LMTP client. Note, however, that in the case of "+" entries (incoming messages), the name shown is that of the default channel for the Dispatcher service listening on the port and interface address for the incoming connection, so is typically merely one of tcp_local (for the SMTP server on port 25) or tcp_submit (for the SMTP SUBMIT server on port 587) or tcp_lmtpss (for the LMTP server); in particular, channel "switching" due to *switchchannel channel option based effects (such as switching to a tcp_intranet channel due to switchchannel or switching to a tcp_auth channel due to saslswitchchannel) is not reflected in such entries. (In the case of "I" records, that is, ETRN records, this "source" channel field instead is used to display the name of the channel which the ETRN command would cause to run.)
  • (5) A plus, +, or minus, -, indicating whether this is an inbound or outbound connection, respectively. That is, a + indicates a connection inbound to an SMTP, SMTP SUBMIT, or LMTP server; a - indicates a connection outbound by a channel acting as an SMTP (or LMTP) client.
  • (6) A code indicating the type of entry; see Connection logging entry action type codes.
  • (7) The transport information. This takes the form:

    
    TCP|local-IP|local-port|remote-IP|remote-port
    
  • (8) The application information. For inbound connections (to the SMTP server), the "O" (that is, open) records will just show "SMTP" in this field; the "C" (that is, close) records will just show "SMTP" unless TLS was used, in which case this field will show "SMTP/TLS-info". The TLS-info string consists of "TLS-bitstrength-cipherinfo". (Note that the cipherinfo field may not be present, and if present may be unreliable in the MTA, especially as of MS 6.0 and later, as the cipher information is not reliably reported back by the underlying NSS library in use.) For outbound connections, the field has some additional information, showing the initial host name (prior to DNS lookup) to which to connect, and the host name found from doing a DNS lookup, that is, the host name to which the connection was really made/attempted. In the case of outbound connections where TLS was used, the TLS information will also be shown in the C (that is, close) record. So for outbound connections, the field takes the form

    
    SMTP/initial-host/DNS-host
    

    or when TLS was used, the C records will take the form

    
    SMTP/initial-host/DNS-host/TLS-info
    

    For instance, initial-host might be a name used for e-mail addresses which merely has MX records, and then DNS-host will be the actual host name to which the connection was made (the name pointed to by an MX record).

  • (9) [Optional---only present if log_message_id=1.] In "I" records, the host name presented on the ETRN command line. In "U" records, the MTA AUTH error, if there was one.
  • (10) [Optional---only present if log_username=1.] In "U" records, the authenticated user.
  • (11) (New in MS 6.2) "C" records may include additional information about the reason for the close, if the close was due to an error. For instance, "Error reading SMTP packet" (in cases where the connection was dropped, for instance due to a network problem or the remote system aborting the connection), or "Timeout after x minutes trying to read SMTP packet" (in cases where the MTA times out the connection due to remote system inactivity).
  • (12) [Optional---only present if log_queue_time=1.] (New in MS 6.3) "O" records may include the "time to open the connection", "Y" records may include the "time attempting to open a connection for an attempt that failed", and "C" records may include the total time the connection was open as a final field. This appears as a ct attribute in XML format logs.
Connection logging entry action type codes
Type Modifiers Description
Actions
C F Connection closed
O   Connection opened
T   PORT_ACCESS mapping table rejection; logged if both bit 1 (value 2) of the log_connection MTA option is set (or overridden by the LOG_CONNECTION TCP/IP-channel-specific option), and the $T flag is used in a PORT_ACCESS rejection entry
U   (New in MS 6.2) Authentication attempt (SMTP AUTH use), whether successful or failed; logged if bit 5 (value 32) of the log_connection MTA option is set
X F Connection rejected, or closed, due to an SMTP level error response
Y   Connection try failed before being established
I   ETRN command received; logged if bit 2 (value 4) of the log_connection MTA option is set (or overridden by the LOG_CONNECTION TCP/IP-channel-specific option)
Modifiers
  F (New in MS 7.1) A *.data-failed file was created; may be reported on "C" or "X" records for SMTP and SMTP SUBMIT connections (but not for LMTP connections, since *.data-failed files are never generated by the LMTP server)

The maximum line length for connection transaction records is 4096 characters. 1The mechanism for computing size values in enqueue entries in the MTA transaction logs was revised for MS 7.0 update 2. Previously message sizes were computed based on counting octets in the input, which did not take various things, including charset-conversion, into account. It was done this way in order to facilitate certain calculations needed for performing message fragmentation. Now that message fragmentation has become a rarity, this approach is no longer appropriate, and the code has been changed to work directly with the output message.


See also: