Understanding Traffic Control Logging
  |
   |
Table of Contents
Description
This chapter explains how to interpret and maintain log files generated by Traffic Control
All log files can be found under logs/ directory in the root directory of the Traffic Control installation. For example:
/opt/TrafficControl/logs/
error_log
logs/error_log file collects any application-level errors that may happen during the run-time of Traffic Control. The information provided by this file is essential for debugging any problems that you may have encounter while using Traffic Control.
traffic_log
logs/traffic_log tracks the traffic going through Traffic Control. It reports which messages were delivered, and which weren't and the reason for non-delivery. It also reports the health of the installation, reputation of the client, and a lot more.
This file contains one line per message (regardless of whether it was delivered or not).
The format of this log line is as follows:
a => the reason a connection was aborted b => MTA connection pool stats "total/free/queued/max" c => last SMTP code sent to the client d => duration of SMTP transaction e => any 4xx or 5xx SMTP codes propagated from the MTA to the client h => client hostname i => client IP and port j => ssl connection information l => last SMTP command issued by the client m => envelope from address n => TC connection stats "total/throttled/from this client" o => was a message delivered or not Y/N p => amount of data received from the client q => queue id issued by the MTA r => envelope recipient list s => Subject header t => the reason a connection was throttled u => the reason a connection was un-throttled or whitelisted v => Message-ID header x => list of triggers activated and the resulting actions z => last SMTP response message sent to the client
Note: In the x value (list of triggers activated), you may see various t= values. For example:
BadRcptCount t=0.01
The t= values indicate how long, in seconds, the given trigger took to run. In the case of the RBL trigger, multiple t= values are given, indicating the times to query each successive RBL.
Logging Configuration
Log4Perl is used for all of Traffic Control's logs in version 3.0 onwards.
We check the configuration file for the logging here
/opt/TrafficControl/conf/log.conf
More information can be found about Log4Perl here
http://log4perl.sourceforge.net/
Logging To Syslog
Since Traffic Control uses Log4Perl for logging purposes, using Syslog is very easy to configure.
You can simply change the appender that is used for the logging in the conf/log.conf file. For instance, changing the traffic_log to use Syslog is done by doing the following.
log4perl.appender.TrafficLogfile = Log::Log4perl::Appender::File
becomes
log4perl.appender.TrafficLogfile = Log::Log4perl::Appender::Syslog
Log Rotation
Certain log files, for instance logs/error_log, may grow relatively quickly and you may want to rotate them periodically. To accomplish that you can use the rotatelogs utility, available from this package.
Should you wish to have this file automatically rotated, you can use
logrotate(8) to accomplish that. In which case perform the
following:
% ln -s /opt/TrafficControl/conf/logrotate.conf \
/etc/logrotate.d/trafficcontrol
and refer to the logrotate(8) manpage for more information about
this daemon, if you aren't using it already.
Log Summarizer Script
This script parses the Traffic Control log file and gives an overview of percentages on delivery success, timings, and trigger actions.
Usage:
scripts/tclogbreakdown.pl [ flags ] <logfile>
where the flags are:
--throttle-only Summarize only those connections that were
throttled
--accept-only Summarize only those connections that were
accepted (whitelisted) at connection time.
--reject-only Summarize only those connections that were
rejected due to some trigger.
--show-declined Also show triggers that ran but did not take
any action.
--decline-only Only show triggers that ran but took no
action.
--delivered-only Analysis only delivered messages.
--not-delivered Analysis only non-delivered messages or
connection attempts.
--ignore-triggers Exclude the results from triggers in
analysizing the log file.
--ignore-exceptions Exclude exceptions in analysising the log
file.
--average-duration Calculate the average duration for each
delivery profile.
--min-duration Calculate the minimum duration for each
delivery profile.
--max-duration Calculate the minimum duration for each
delivery profile.
--delivered-YDNR This no longer relates to Traffic Control
3.0 and beyond.
It shows legacy delivery statuses.
--show-throttle-reason Show the reason the connection was
throttled. This is the 't' field in the log.
--show-last-command Show the reason the connection was
unthrottled. This is the 'u' field in the log.
For example, here we are looking at the average durations of messages that were delivered ( --delivered-only ), but were throttled ( --throttle-only ). We also want to include information on triggers that ran, but took no action ( --show-declined ).
nice ./tclogbreakdown.pl \
--average-duration \
--throttle-only \
--delivered-only \
--show-declined \
/opt/tc/TrafficControl/logs/traffic_log
This would output something along the lines of the following.
13503 : TOTAL (d=67.1)
(out of 2665703 0.5%)
100.0% 13503 : o=Y (d=67.1)
0.1% 16 : o=Y Always=throttle RBL=decline (d=123.8)
0.0% 1 : o=Y Always=throttle RBL=decline ClamAV=decline (d=130.0)
0.7% 95 : o=Y P0F=throttle RBL=decline ClamAV=decline (d=147.2)
0.1% 13 : o=Y RBL=throttle P0F=decline (d=90.5)
98.8% 13337 : o=Y RBL=throttle P0F=decline ClamAV=decline (d=66.5)
0.3% 41 : o=Y RBL=throttle P0F=decline ClamAV=decline Duplicates=accept (d=54.4)
Since this machine is a low priority MX it will receive almost no real mail. Therefore we can see that only 13,503 out of 2,665,703 (0.5%) messages were throttled and delivered.
Looking at one of these lines, we can see that 98.8% of the non-delivered messages were throttled by RBLs and ran P0F and ClamAV, which both took no action. The average delivery time in that case if 66.5 seconds.
|
|