File: spec_51.html

package info (click to toggle)
exim-html 3.20-1
links: PTS
area: main
in suites: etch, etch-m68k, sarge, woody
size: 2,868 kB
ctags: 4,188
sloc: makefile: 40; sh: 19
file content (609 lines) | stat: -rw-r--r-- 21,750 bytes
<HTML>
<HEAD>
<!-- This HTML file has been created by texi2html 1.52
     from spec on 25 November 2000 -->

<TITLE>Exim Specification - 51. Log files</TITLE>
</HEAD>
<body bgcolor="#FFFFFF" text="#00005A" link="#FF6600" alink="#FF9933" vlink="#990000">
Go to the <A HREF="spec_1.html">first</A>, <A HREF="spec_50.html">previous</A>, <A HREF="spec_52.html">next</A>, <A HREF="spec_59.html">last</A> section, <A HREF="spec_toc.html">table of contents</A>.
<P><HR><P>


<H1><A NAME="SEC852" HREF="spec_toc.html#TOC852">51. Log files</A></H1>
<P>
<A NAME="IDX1886"></A>
Exim writes three different logs, referred to as the main log, the reject log,
and the panic log.

</P>

<UL>

<LI>

<A NAME="IDX1887"></A>
The main log records the arrival of each message and each delivery in a single
logical line in each case. The format is as compact as possible, in an attempt
to keep down the size of log files. Two-character flag sequences make it easy
to pick out these lines. A number of other events are also recorded in the main
log. Some of these entries can be suppressed by changing the value of the
<EM>log_level</EM> and <EM>log_queue_run_level</EM> configuration options.
<font color=green>
There are also a number of options whose names start with <EM>log_</EM> which can be
used to request additional logging.
</font>

<LI>

<A NAME="IDX1888"></A>
The reject log records information from messages that are rejected as a result
of a configuration option (that is, for policy reasons). If the message's
header has been read, its contents are written to this log, following a copy of
the one-line message that is also written to the main log.

<LI>

<A NAME="IDX1889"></A>
<A NAME="IDX1890"></A>
The panic log is written when Exim suffers a disastrous error. Often (but not
always) it bombs out afterwards. The panic log should be checked regularly to
pick up any problems. When Exim cannot open its panic log, it tries as a last
resort to write to the system log (syslog). This is opened with
LOG_PID+LOG_CONS and the facility code of LOG_MAIL. The message itself is
written at priority LOG_CRIT.
</UL>

<P>
The logs may be written to local files, or to syslog, or both. However, it
should be noted that many syslog implementations use UDP as a transport, and
are therefore unreliable in the sense that messages are not guaranteed to
arrive at the loghost, nor is the ordering of messages necessarily maintained.
It has also been reported that on large log files (tens of megabytes) you may
need to tweak syslog to prevent it syncing the file with each write -- on Linux
this has been seen to make syslog take 90% plus of CPU time.

</P>
<P>
<A NAME="IDX1891"></A>
<A NAME="IDX1892"></A>
<A NAME="IDX1893"></A>
<A NAME="IDX1894"></A>
The destination for Exim's logs is configured by setting LOG_FILE_PATH in
<TT>`Local/Makefile'</TT> or by setting <EM>log_file_path</EM> in the run time configuration.
This latter string is expanded, so it can contain, for example, references to
the host name:

<PRE>
log_file_path = /var/log/$primary_hostname/exim_%slog
</PRE>

<P>
It is generally advisable, however, to set the string in <TT>`Local/Makefile'</TT>
rather than at run time, because then the setting is available right from the
start of Exim's execution. Otherwise, if there's something it wants to log
before it has read the configuration file (for example, an error in the
configuration file) it will not use the path you want, and may not be able to
log at all.

</P>
<P>
The value of LOG_FILE_PATH or <EM>log_file_path</EM> is a colon-separated
list, currently limited to at most two items.
<font color=green>
This is one option where the facility for changing a list separator may not be
used. The list must always be colon-separated.
</font>
If an item in the list is `syslog' then syslog is used; otherwise the item must
either be an absolute path, containing `%s' at the point where `main',
`reject', or `panic' is to be inserted, or be empty, implying the use of the
default path, which is `log/%slog' in the spool directory. The default path is
used if nothing is specified. Here are some examples of possible settings:

<PRE>
LOG_FILE_PATH=syslog                      syslog only
LOG_FILE_PATH=:syslog                     syslog and default path
LOG_FILE_PATH=syslog : /usr/log/exim_%s   syslog and specified path
LOG_FILE_PATH=/usr/log/exim_%s            specified path only
</PRE>

<P>
If there are more than two paths in the list, the first is used and a panic
error is logged.

</P>

<P>



<H2><A NAME="SEC853" HREF="spec_toc.html#TOC853">51.1 Logging to local files</A></H2>

<P>
A utility script called <EM>exicyclog</EM> which renames and compresses the main and
reject logs each time it is called is provided for use with logs written to
local files. The maximum number of old logs to keep can be set. It is suggested
this is run as a daily <EM>cron</EM> job. A Perl script called <EM>eximstats</EM> which does
simple analysis of main log files is also provided. See chapter 53 for
details of both these utilities.

</P>
<P>
An Exim delivery process opens the main log when it first needs to write to it,
and it keeps the file open in case subsequent entries are required -- for
example, if a number of different deliveries are being done for the same
message. However, remote SMTP deliveries can take a long time, and this means
that the file may be kept open long after it is renamed if <EM>exicyclog</EM> or
something similar is being used to rename log files on a regular basis. To
ensure that a switch of log files is noticed as soon as possible, Exim calls
<EM>stat()</EM> on the main log's name before reusing an open file, and if the file
does not exist, or its inode has changed, the old file is closed and Exim
tries to open the main log from scratch. Thus, an old log file may remain open
for quite some time, but no Exim processes should write to it once it has been
renamed.

</P>



<H2><A NAME="SEC854" HREF="spec_toc.html#TOC854">51.2 Logging to syslog</A></H2>

<P>
The use of syslog does not change what Exim logs or the format of its messages.
The same strings are written to syslog as to log files. The syslog `facility'
is set to LOG_MAIL, and the program name to `exim'. On systems that permit
it (all except ULTRIX) the LOG_PID flag is set so that the <EM>syslog()</EM> call
adds the pid as well as the time and host name to each line. The three log
streams are mapped onto syslog priorities as follows:

</P>

<UL>

<LI>

<EM>mainlog</EM> is mapped to LOG_INFO

<LI>

<EM>rejectlog</EM> is mapped to LOG_NOTICE

<LI>

<EM>paniclog</EM> is mapped to LOG_ALERT
</UL>

<P>
Many log lines are written to both <EM>mainlog</EM> and <EM>rejectlog</EM>, so there will be
duplicates if these are routed by syslog to the same place.

</P>
<P>
Exim's log lines can sometimes be very long, and some of its <EM>rejectlog</EM>
entries contain multiple lines when headers are included. To cope with both
these cases, entries written to syslog are split into separate <EM>syslog()</EM> calls
at each internal newline, and also after a maximum of 1000 characters. To make
it easy to re-assemble them later, each component of a split entry starts with
a string of the form `[&#60;<EM>n</EM>&#62;/&#60;<EM>m</EM>&#62;]' or `[&#60;<EM>n</EM>&#62;\&#60;<EM>m</EM>&#62;]' where &#60;<EM>n</EM>&#62; is the
component number and &#60;<EM>m</EM>&#62; is the total number of components in the entry. The
/ delimiter is used when the line was split because it was too long; if it was
split because of an internal newline, the \ delimiter is used. For example,
supposing the length limit to be 70 instead of 1000, the following would be the
result of a typical rejection message to <EM>mainlog</EM> (LOG_INFO), each line in
addition being preceded by the time, host name, and pid as added by syslog:

<PRE>
$smc{[1/3] 1999-09-16 16:09:43 11RdAL-0006pc-00 rejected from [127.0.0.1] (ph10):
[2/3]  syntax error in 'From' header when scanning for sender: missing or ma
[3/3] lformed local part in "&#60;&#62;" (envelope sender is &#60;ph10@cam.ac.uk&#62;)}
</PRE>

<P>
The same error might cause the following lines to "rejectlog" (LOG_NOTICE):

<PRE>
$smc{[1/14] 1999-09-16 16:09:43 11RdAL-0006pc-00 rejected from [127.0.0.1] (ph10):
[2/14]  syntax error in 'From' header when scanning for sender: missing or ma
[3\14] lformed local part in "&#60;&#62;" (envelope sender is &#60;ph10@cam.ac.uk&#62;)
[4\14] Recipients: ph10@some.domain.cam.ac.uk
[5\14] P Received: from [127.0.0.1] (ident=ph10)
[6\14]        by xxxxx.cam.ac.uk with smtp (Exim 3.10 #27)
[7\14]        id 11RdAL-0006pc-00
[8\14]        for ph10@cam.ac.uk; Thu, 16 Sep 1999 16:09:43 +0100
[9\14] F From: &#60;&#62;
[10\14]   Subject: this is a test header
[11\14]   X-something: this is another header
[12\14] I Message-Id: &#60;E11RdAL-0006pc-00@xxxxx.cam.ac.uk&#62;
[13\14] B Bcc:
[14/14]   Date: Thu, 16 Sep 1999 16:09:43 +0100}
</PRE>

<P>
Log lines that are neither too long nor contain newlines are written to syslog
without modification, for example:

<PRE>
1999-09-16 16:09:47 SMTP connection from [127.0.0.1] closed by QUIT
</PRE>

<P>
The times added by syslog are normally the same as Exim's time stamps (though
in a different format, and without the year) but can sometimes be different.

</P>
<P>
If only syslog is being used, the Exim monitor is unable to provide a log tail
display, unless syslog is routing <EM>mainlog</EM> to a file on the local host and the
environment variable EXIMON_LOG_FILE_PATH is set to tell the monitor
where it is.

</P>


<H2><A NAME="SEC855" HREF="spec_toc.html#TOC855">51.3 Logging message reception</A></H2>

<P>
<A NAME="IDX1895"></A>
<A NAME="IDX1896"></A>
The format of the single-line entry in the main log that is written for every
message received is shown in the example below, which is split over several
lines in order to fit it on the page:

<PRE>
1995-10-31 08:57:53 0tACW1-0005MB-00 &#60;= kryten@dwarf.fict.book
  H=mailer.fict.book [123.123.123.123] U=exim
  P=smtp S=5678 id=&#60;<EM>incoming message id</EM>&#62;
</PRE>

<P>
The H and U fields identify the remote host and record the RFC 1413 identity of
the user that sent the message, if one was received. The number given in square
brackets is the IP address of the sending host. If there is just a single host
name in the H field, as above, it has been verified to correspond to the IP
address (see the <EM>host_lookup</EM> option). If the name is in parentheses,
it was the name quoted by the remote host in the SMTP HELO or EHLO
command, and has not been verified. If verification yields a different name to
that given for HELO or EHLO, the verified name appears first,
followed by the HELO or EHLO name in parentheses.

</P>
<P>
Misconfigured hosts (and mail forgers) sometimes put an IP address, with or
without brackets, in the HELO or EHLO command, leading to entries in
the log containing things like

<PRE>
H=(10.21.32.43) [123.99.8.34]
H=([10.21.32.43]) [123.99.8.34]
</PRE>

<P>
which can be confusing. Only the final address in square brackets can be relied
on. For locally generated messages, the H field is omitted, and the U field
contains the login name of the caller of Exim.

</P>
<P>
For all messages, the P field specifies the protocol used to receive the
message. This is set to `asmtp' for messages received from hosts which have
authenticated themselves using the SMTP AUTH command. In this case there is
an additional item A= followed by the name of the authenticator that was used.
If an authenticated identification was set up by the authenticator's
<EM>server_set_id</EM> option, this is logged too, separated by a colon from the
authenticator name.

</P>
<P>
The id field records the existing message id, if present.
<A NAME="IDX1897"></A>
The size of the received message is given by the S field. When the message is
delivered, headers may get removed or added, so that the size of delivered
copies of the message may not correspond with this value (and indeed may be
different to each other).

</P>

<P>
<A NAME="IDX1898"></A>
If the <EM>log_received_sender</EM> option is on, the unrewritten original sender of
a message is added to the end of the log line that records the message's
arrival, after the word `from'.
<A NAME="IDX1899"></A>
If the <EM>log_received_recipients</EM> option is on, a list of all the recipients
of a message is added to the log line, preceded by the word `for'. This happens
after any unqualified addresses are qualified, but before any rewriting is
done.
<A NAME="IDX1900"></A>
If the <EM>log_subject</EM> option is on, the subject of the message is added to the
log line, preceded by `T=' (T for `topic', since S is already used for `size').

</P>
<P>
A delivery error message is shown with the sender address `&#60;&#62;', and if it is a
locally-generated error message, this is normally followed by an item of the
form

<PRE>
R=&#60;<EM>message id</EM>&#62;
</PRE>

<P>
which is a reference to the local identification of the message that caused the
error message to be sent.

</P>



<H2><A NAME="SEC856" HREF="spec_toc.html#TOC856">51.4 Logging deliveries</A></H2>

<P>
The format of the single-line entry in the main log that is written for every
delivery is shown in one of the examples below, for local and remote deliveries,
respectively. Each example has been split into two lines in order to fit
it on the page:

<PRE>
1995-10-31 08:59:13 0tACW1-0005MB-00 =&#62; marv &#60;marv@hitch.fict.book&#62;
  D=localuser T=local_delivery
1995-10-31 09:00:10 0tACW1-0005MB-00 =&#62; monk@holistic.fict.book
  R=lookuphost T=smtp H=holistic.fict.book [234.234.234.234]
</PRE>

<P>
For ordinary local deliveries, the original address is given in angle brackets
after the final delivery address, which might be a pipe or a file. If
intermediate address(es) exist between the original and the final address, the
last of these is given in parentheses after the final address.
However, <EM>log_all_parents</EM> can be set to cause all intermediate addresses to
be logged.

</P>
<P>
If a shadow transport was run after a successful local delivery, the log line
for the successful delivery has an item added on the end, of the form

<PRE>
ST=&#60;<EM>shadow transport name</EM>&#62;
</PRE>

<P>
If the shadow transport did not succeed, the error message is put in
parentheses afterwards.

</P>
<P>
When a local delivery occurs as a result of routing rather than directing (for
example, messages are being batched up for transmission by some other means),
the log entry looks more like that for a remote delivery.

</P>
<P>
For normal remote deliveries, if the <EM>log_smtp_confirmation</EM> option is on,
the response to the final `.' in the SMTP transmission is added to the log
line, preceded by `C='. If the final delivery address is not the same as the
original address (owing to changes made by routers), the original is shown in
angle brackets.

</P>
<P>
The generation of a reply message by a filter file gets logged as a `delivery'
to the addressee, preceded by `&#62;'. The D and T items record the director and
transport. For remote deliveries, the router, transport, and host are recorded.

</P>
<P>
When more than one address is included in a single delivery (for example, two
SMTP
RCPT
commands in one transaction) then the second and subsequent addresses are
flagged with `-&#62;' instead of `=&#62;'. When two or more messages are
delivered down a single SMTP connection, an asterisk follows the IP address in
the log lines for the second and subsequent messages.

</P>
<P>
When the -<EM>N</EM> debugging option is used to prevent delivery from actually
occurring, log entries are flagged with `*&#62;' instead of `=&#62;'.

</P>
<P>
<A NAME="IDX1901"></A>
<A NAME="IDX1902"></A>
When a message is discarded as a result of the command `seen finish' being
obeyed in a filter file which generates no deliveries, a log entry of the form

<PRE>
1998-12-10 00:50:49 0znuJc-0001UB-00 =&#62; discarded
  &#60;low.club@trick4.bridge&#62; D=userforward
</PRE>

<P>
is written, to record why no deliveries are logged.

</P>


<H2><A NAME="SEC857" HREF="spec_toc.html#TOC857">51.5 Deferred deliveries</A></H2>

<P>
When a delivery is deferred, a line of the following form is logged:

<PRE>
1995-12-19 16:20:23 0tRiQz-0002Q5-00 == marvin@endrest.book
  T=smtp defer (146): Connection refused
</PRE>

<P>
In the case of remote deliveries, the error is the one that was given for the
last IP address that was tried. Details of individual SMTP failures are also
written to the log, so the above line would be preceded by something like

<PRE>
1995-12-19 16:20:23 0tRiQz-0002Q5-00 Failed to connect to endrest.book
  [239.239.239.239]: Connection refused
</PRE>

<P>
When a deferred address is skipped because its retry time has not been reached,
a message is written to the log, but this can be suppressed by changing the
<EM>log_level</EM> option.

</P>


<H2><A NAME="SEC858" HREF="spec_toc.html#TOC858">51.6 Delivery failures</A></H2>

<P>
<A NAME="IDX1903"></A>
If a delivery fails, a line of the following form is logged:

<PRE>
1995-12-19 16:20:23 0tRiQz-0002Q5-00 ** jim@trek99.film
  &#60;jimtrek99.film&#62;: unknown mail domain
</PRE>

<P>
This is followed (eventually) by a line giving the address to which the
delivery error has been sent.

</P>
<P>
<font color=green>


<H2><A NAME="SEC859" HREF="spec_toc.html#TOC859">51.7 Fake deliveries</A></H2>

<P>
<A NAME="IDX1904"></A>
If a delivery does not actually take place because the -<EM>N</EM> options has been
used to suppress it, an apparently normal delivery line is written to the log,
except that `=&#62;' is replaced by `*&#62;'.
</font>

</P>


<H2><A NAME="SEC860" HREF="spec_toc.html#TOC860">51.8 Completion</A></H2>

<P>
A line of the form

<PRE>
1995-10-31 09:00:11 0tACW1-0005MB-00 Completed
</PRE>

<P>
is written to the main log when a message is about to be removed from the spool
at the end of its processing.

</P>


<H2><A NAME="SEC861" HREF="spec_toc.html#TOC861">51.9 Other log entries</A></H2>

<P>
Various other types of log entry are written from time to time. Most should be
self-explanatory. Among the more common are:

</P>

<UL>

<LI>

<A NAME="IDX1905"></A>
<EM>retry time not reached</EM>  An address previously suffered a temporary error
during directing or routing or local delivery, and the time to retry it has not
yet arrived.

<LI>

<EM>retry time not reached for any host</EM>  An address previously suffered
temporary errors during remote delivery, and the retry time has not yet arrived
for any of the hosts to which it is routed.

<LI>

<A NAME="IDX1906"></A>
<EM>spool file locked</EM>  An attempt to deliver a message cannot proceed because
some other Exim process is already working on the message. This can be quite
common if queue running processes are started at frequent intervals. The
<EM>exiwhat</EM> utility script can be used to find out what Exim processes are doing.
</UL>



<H2><A NAME="SEC862" HREF="spec_toc.html#TOC862">51.10 Log level</A></H2>

<P>
<A NAME="IDX1907"></A>
The <EM>log_level</EM> configuration option controls the amount of data written to
the main log. The higher the number, the more is written. A value of 6 causes
all possible messages to appear, though higher levels may get defined in the
future. Zero sets a minimal level of logging, with higher levels adding the
following, successively:

<PRE>
1   rejections because of policy
    re-addressing by the system filter

2   $t rejections because of message size

3   $t verification failures

4   $t SMTP timeouts
    SMTP connection refusals because too busy
    SMTP unexpected connection loss
    SMTP (dis)connections when <EM>log_smtp_connections</EM> is set
    SMTP syntax errors when <EM>log_smtp_syntax_errors</EM> is set
    non-immediate delivery of SMTP messages because of load level,
    or number of connections etc.

5   $t `retry time not reached [for any host]'
    `spool file locked' (i.e. some other process is delivering the message)
    `message is frozen' (when skipping it in a queue run)
    `error message sent to ...'

6   $t invalid HELO and EHLO arguments (see <EM>helo_verify</EM>)
</PRE>

<P>
The default log level is 5, which is on the verbose side. Rejection information
is still written to the reject log in all cases.

</P>


<H2><A NAME="SEC863" HREF="spec_toc.html#TOC863">51.11 Message log</A></H2>

<P>
<A NAME="IDX1908"></A>
<A NAME="IDX1909"></A>
In addition to the four main log files, Exim writes a log file for each message
that it handles. The names of these per-message logs are the message ids, and
<A NAME="IDX1910"></A>
they are kept in the <EM>msglog</EM> sub-directory of the spool directory. A single
line is written to the message log for each delivery attempt for each address.
It records either a successful delivery, or the reason (temporary or permanent)
for failure. If the log level is 5 or higher, `retry time not reached' messages
are also written to individual message logs.
If the log level is 4 or less, they are suppressed after the first delivery
attempt.

</P>
<P>
When a local part is expanded by aliasing or a forwarding file, a line is
written to the message log when all its child deliveries are completed. SMTP
connection failures for each remote host are also logged here. The log is
deleted when processing of the message is complete,
<A NAME="IDX1911"></A>
unless <EM>preserve_message_logs</EM> is set, but this should be used only with
great care because they can fill up your disc very quickly.

</P>

<P><HR><P>
Go to the <A HREF="spec_1.html">first</A>, <A HREF="spec_50.html">previous</A>, <A HREF="spec_52.html">next</A>, <A HREF="spec_59.html">last</A> section, <A HREF="spec_toc.html">table of contents</A>.
</BODY>
</HTML>