Next: , Previous: , Up: Tutorial   [Contents][Index]

3.19 Logging and Debugging

Depending on its operation mode, mailfromd tries to guess whether it is appropriate to print its diagnostics and informational messages on standard error or to send them to syslog. Standard error is assumed if the program is run with one of the following command line options:

If none of these are used, mailfromd switches to syslog as soon as it finishes its startup. There are two ways to communicate with the syslogd daemon: using the syslog function from the system libc library, which is a blocking implementation in most cases, or via internal, asynchronous, syslog implementation. Whether the latter is compiled in and which implementation is used by default is determined when compiling the package, as described in Using non-blocking syslog.

The --logger command line option allows you to manually select the diagnostic channel:

--logger=stderr

Log everything to the standard error.

--logger=syslog

Log to syslog.

--logger=syslog:async

Log to syslog using the asynchronous syslog implementation.

Another way to select the diagnostic channel is by using the logger statement in the configuration file. The statement takes the same argument as its command line counterpart.

The rest of details regarding diagnostic output are controlled by the logging configuration statement.

The default syslog facility is ‘mail’; it can be changed using the --log-facility command line option or facility statement. Argument in both cases is a valid facility name, i.e. one of: ‘user’, ‘daemon’, ‘auth’, ‘authpriv’, ‘mail’, and ‘local0’ through ‘local7’. The argument can be given in upper, lower or mixed cases, and it can be prefixed with ‘log_’:

Another syslog-related parameter that can be configured is the tag, which identifies mailfromd messages. The default tag is the program name. It is changed by the --log-tag (-L command line option and the tag logging statement.

The following example configures both the syslog facility and tag:

logging {
  facility local7;
  tag "mfd";
}

As any other UNIX utility, mailfromd is very quiet unless it has something important to communicate, such as, e.g. an error condition. A set of command line options is provided for controlling the verbosity of its output.

The --trace option enables tracing Sendmail actions executed during message verifications. When this option is given, any accept, discard, continue, etc. triggered during execution of your filter program will leave their traces in the log file. Here is an example of how it looks like (syslog time stamp, tag and PID removed for readability):

k8DHxvO9030656: /etc/mailfromd.mfl:45: reject 550 5.1.1 Sender validity
not confirmed

This shows that while verifying the message with IDk8DHxvO9030656’ the reject action was executed by filter script /etc/mailfromd.mfl at line 45.

The use of message ID in the log deserves a special notice. The program will always identify its log messages with the ‘Message-Id’, when it is available. Your responsibility as an administrator is to make sure it is available by configuring your MTA to export the macro ‘i’ to mailfromd. The rule of thumb is: make ‘i’ available to the very first handler mailfromd executes. It is not necessary to export it to the rest of the handlers, since mailfromd will cache it. For example, if your filter script contains ‘envfrom’ and ‘envrcpt’ handlers, export ‘i’ for ‘envfrom’. The exact instructions on how to ensure it depend on the MTA you use. For ‘Sendmail’, refer to Sendmail. For MeTA1, see MeTA1, and pmult-macros. For ‘Postfix’, see Postfix.

To push log verbosity further, use the debug configuration statement (see conf-debug) or its command line equivalent, --debug (-d, see --debug). Its argument is a debugging level, whose syntax is described in http://mailutils.org/wiki/Debug_level.

The debugging output is controlled by a set of levels, each of which can be set independently of others. Each debug level consists of a category name, which identifies the part of package for which additional debugging is desired, and a level number, which indicates how verbose should its output be.

Valid debug levels are:

error

Displays error conditions which are normally not reported, but passed to the caller layers for handling.

trace0 through trace9

Ten levels of verbosity, trace0 producing less output, trace9 producing the maximum amount of output.

prot

Displays network protocol interaction, where applicable.

The overall debugging level is specified as a list of individual levels, delimited with semicolons. Each individual level can be specified as one of:

!category

Disables all levels for the specified category.

category

Enables all levels for the specified category.

category.level

For this category, enables all levels from ‘error’ to level, inclusive.

category.=level

Enables only the given level in this category.

category.!level

Disables all levels from ‘error’ to level, inclusive, in this category.

category.!=level

Disables only the given level in this category.

category.levelA-levelB

Enables all levels in the range from levelA to levelB, inclusive.

category.!levelA-levelB

Disables all levels in the range from levelA to levelB, inclusive.

Additionally, a comma-separated list of level specifications is allowed after the dot. For example, the following specification:

acl.prot,!=trace9,!trace2

enables in category acl all levels, except trace9, trace0, trace1, and trace2.

Implementation and applicability of each level of debugging differs between various categories. Categories built-in to mailutils are described in http://mailutils.org/wiki/Debug_level. Mailfromd introduces the following additional categories:

db
trace0

Detailed debugging info about expiration and compaction.

trace5

List records being removed.

dns
trace8

Verbose information about attempted DNS queries and their results.

trace9

Enables ‘libadns’ internal debugging.

srvman
trace0

Additional information about normal conditions, such as subprocess exiting successfully or a remote party being allowed access by ACL.

trace1

Detailed transcript of server manager actions: startup, shutdown, subprocess cleanups, etc.

trace3

Additional info about fd sets.

trace4

Individual subserver status information.

trace5

Subprocess registration.

pmult
trace1

Verbosely list incoming connections, functions being executed and erroneous conditions: missing headers in SMFIR_CHGHEADER, undefined macros, etc.

trace2

List milter requests being processed.

trace7

List SMTP body content in SMFIR_REPLBODY requests.

error

Verbosely list mild errors encountered: bad recipient addresses, etc.

callout
trace0

Verification session transcript.

trace1

MX servers checks.

trace5

List emails being checked.

trace9

Additional info.

main
trace5

Info about hostnames in relayed domain list

engine

Debugging of the virtual engine.

trace5

Message modification lists.

trace6

Debug message modification operations and Sendmail macros registered.

trace7

List SMTP stages (‘xxfi_*’ calls).

trace9

Cleanup calls.

pp

Preprocessor.

trace1

Show command line of the preprocessor being run.

prog
trace8

Stack operations

trace9

Debug exception state save/restore operations.

spf
error

Mild errors.

trace0

List calls to ‘spf_eval_record’, ‘spf_test_record’, ‘spf_check_host_internal’, etc.

trace1

General debug info.

trace6

Explicitly list A records obtained when processing the ‘a’ SPF mechanism.

Categories starting with ‘bi_’ debug built-in modules:

bi_db

Database functions.

trace5

List database look-ups.

trace6

Trace operations on the greylisting database.

bi_sa

SpamAssassin and ClamAV API.

trace1

Report the findings of the ‘clamav’ function.

trace9

Trace payload in interactions with ‘spamd’.

bi_io

I/O functions.

trace1

Debug the following functions: open, spawn, write.

trace2

Report stderr redirection.

trace3

Report external commands being run.

bi_mbox

Mailbox functions.

trace1

Report opened mailboxes.

bi_other

Other built-ins.

trace1

Report results of checks for existence of usernames.

For example, the following invocation enables levels up to ‘trace2’ in category ‘engine’, all levels in category ‘savsrv’ and levels up to ‘trace0’ in category ‘srvman’:

$ mailfromd --debug='engine.trace2;savsrv;srvman.trace0'

You need to have sufficient knowledge about mailfromd internal structure to use this form of the --debug option.

To control the execution of the sender verification functions (see SMTP Callout functions), you may use --transcript (-X) command line option which enables transcripts of SMTP sessions in the logs. Here is an example of the output produced running mailfromd --transcript:

k8DHxlCa001774: RECV: 220 spf-jail1.us4.outblaze.com ESMTP Postfix
k8DHxlCa001774: SEND: HELO mail.gnu.org.ua
k8DHxlCa001774: RECV: 250 spf-jail1.us4.outblaze.com
k8DHxlCa001774: SEND: MAIL FROM: <>
k8DHxlCa001774: RECV: 250 Ok
k8DHxlCa001774: SEND: RCPT TO: <t1Kmx17Q@malaysia.net>
k8DHxlCa001774: RECV: 550 <>: No thank you rejected: Account
 Unavailable: Possible Forgery
k8DHxlCa001774: poll exited with status: not_found; sent
 "RCPT TO: <t1Kmx17Q@malaysia.net>", got "550 <>: No thank you
 rejected: Account Unavailable: Possible Forgery"
k8DHxlCa001774: SEND: QUIT

Next: , Previous: , Up: Tutorial   [Contents][Index]