Hi,
I'm finding that hook_reset_transation is firing three times for just
one msg.
I've extended the adaptive logging plugin as follows:
sub init {
my ( $self, $qp ) = @_;
$self->isa_plugin('logging/adaptive');
}
I then also have a register routine to grab some config settings:
sub register {
my ( $self, $qp, %args ) = @_;
$self->{_acceptlevel} = LOGERROR;
if ( defined( $args{acceptlevel} ) ) {
if ( $args{acceptlevel} =~ /^\d+$/ ) {
$self->{_acceptlevel} = $args{acceptlevel};
}
else {
$self->{_acceptlevel} = log_level( $args{acceptlevel} );
}
}
$self->{_maxlevel} = LOGWARN;
if ( defined( $args{maxlevel} ) ) {
if ( $args{maxlevel} =~ /^\d+$/ ) {
$self->{_maxlevel} = $args{maxlevel};
}
else {
$self->{_maxlevel} = log_level( $args{maxlevel} );
}
}
$self->{_rejectlevel} = LOGWARN;
if ( defined( $args{rejectlevel} ) ) {
if ( $args{rejectlevel} =~ /^\d+$/ ) {
$self->{_rejectlevel} = $args{rejectlevel};
}
else {
$self->{_rejectlevel} = log_level( $args{rejectlevel} );
}
}
$self->{_acceptprefix} = '++';
if ( defined $args{acceptprefix} and $args{acceptprefix} =~ /^(.+)$/ ) {
$self->{_acceptprefix} = $1;
}
$self->{_rejectprefix} = '--';
if ( defined $args{rejectprefix} and $args{rejectprefix} =~ /^(.+)$/ ) {
$self->{_rejectprefix} = $1;
}
# If you want to capture this log entry with this plugin, you need to
# wait until after you register the plugin
$self->log( LOGINFO, 'Initializing logging::trilog plugin' );
}
hook_reset_transatiion is as follows:
sub hook_reset_transaction { # slog
# fires when a message is accepted
my ( $self, $transaction, @args ) = @_;
return DECLINED if $self->{_denied};
# Don't call the parent hook - don't want that functionality.
# $self->SUPER::hook_reset_transaction( $transaction, @args );
# code here to write accepted log
warn( ${$} . ' ' . $self->{_acceptprefix} . ' '
. join( "\t", ('foo', 'bar' ))
. "\n");
1;
}
This produces the following log output for each msg:
Accepted connection 0/20 from 192.168.1.60 / batmobile.robinbowes.com
Connection from batmobile.robinbowes.com [192.168.1.60]
running plugin (connect): check_earlytalker
check_earlytalker plugin: remote host said nothing spontaneous, proceeding
Plugin check_earlytalker, hook connect returned DECLINED,
running plugin (connect): check_relay
trying to get config for relayclients
trying to get config for morerelayclients
Plugin check_relay, hook connect returned DECLINED,
running plugin (connect): dnsbl
dnsbl plugin: RBLSMTPD not set for 192.168.1.60
trying to get config for dnsbl_allow
trying to get config for dnsbl_zones
dnsbl plugin: Checking 60.1.168.192.rbl.mail-abuse.org for TXT record in
the background
dnsbl plugin: Checking 60.1.168.192.relays.ordb.org for TXT record in
the background
dnsbl plugin: Checking 60.1.168.192.spamsources.fabel.dk for TXT record
in the background
dnsbl plugin: Checking 60.1.168.192.sbl.spamhaus.org for TXT record in
the background
Plugin dnsbl, hook connect returned DECLINED,
trying to get config for smtpgreeting
trying to get config for me
220 batmobile.robinbowes.com ESMTP qpsmtpd 0.32 ready; send us your
mail, but not your spam.
trying to get config for timeoutsmtpd
trying to get config for timeout
dispatching EHLO batmobile.robinbowes.com
running plugin (ehlo): tls
Plugin tls, hook ehlo returned DECLINED,
running plugin (ehlo): check_spamhelo
trying to get config for badhelo
Plugin check_spamhelo, hook ehlo returned DECLINED,
trying to get config for me
trying to get config for databytes
250-batmobile.robinbowes.com Hi batmobile.robinbowes.com [192.168.1.60]
250-PIPELINING
250-8BITMIME
250-STARTTLS
250 AUTH PLAIN LOGIN
dispatching MAIL FROM:<[EMAIL PROTECTED]>
--> running plugin (reset_transaction): logging::trilog
--> Plugin logging::trilog, hook reset_transaction returned DONE,
full from_parameter: FROM:<[EMAIL PROTECTED]>
from email address : [<[EMAIL PROTECTED]>]
running plugin (mail): tls
Plugin tls, hook mail returned DECLINED,
running plugin (mail): check_badmailfrom
trying to get config for badmailfrom
Plugin check_badmailfrom, hook mail returned DECLINED,
getting mail from <[EMAIL PROTECTED]>
250 <[EMAIL PROTECTED]>, sender OK - how exciting to get
mail from you!
dispatching RCPT TO:<[EMAIL PROTECTED]>
to email address : [<[EMAIL PROTECTED]>]
running plugin (rcpt): tls
Plugin tls, hook rcpt returned DECLINED,
running plugin (rcpt): check_validrcptto_cdb
check_validrcptto_cdb plugin: Relaying detected - skipping recipient check
Plugin check_validrcptto_cdb, hook rcpt returned DECLINED,
running plugin (rcpt): check_badmailfrom
Plugin check_badmailfrom, hook rcpt returned DECLINED,
running plugin (rcpt): check_badrcptto
trying to get config for badrcptto
Plugin check_badrcptto, hook rcpt returned DECLINED,
running plugin (rcpt): dnsbl
trying to get config for dnsbl_zones
dnsbl plugin: waiting for dnsbl dns
dnsbl plugin: DONE waiting for dnsbl dns, got 2 answers ...
trying to get config for dnsbl_zones
dnsbl plugin: waiting for dnsbl dns
dnsbl plugin: DONE waiting for dnsbl dns, got 1 answers ...
trying to get config for dnsbl_zones
dnsbl plugin: waiting for dnsbl dns
dnsbl plugin: DONE waiting for dnsbl dns, got 1 answers ...
Plugin dnsbl, hook rcpt returned DECLINED,
running plugin (rcpt): rcpt_ok
trying to get config for me
trying to get config for rcpthosts
Plugin rcpt_ok, hook rcpt returned OK,
250 <[EMAIL PROTECTED]>, recipient ok
dispatching DATA
running plugin (data): tls
Plugin tls, hook data returned DECLINED,
354 go ahead
trying to get config for databytes
max_size: 0 / size: 0
trying to get config for timeout
max_size: 0 / size: 227
trying to get config for me
running plugin (data_post): spamassassin
spamassassin plugin: check_spam
spamassassin plugin: check_spam: connected to spamd
spamassassin plugin: check_spam: finished sending to spamd
spamassassin plugin: check_spam: spamd: SPAMD/1.1 0 EX_OK
2006-02-20 00:43:08.025794500
trying to get config for me
spamassassin plugin: check_spam: spamd: Content-length: 37
spamassassin plugin: check_spam: spamd: Spam: False ; -3.4 / 5.0
spamassassin plugin: check_spam: spamd:
spamassassin plugin: check_spam: finished reading from spamd
spamassassin plugin: check_spam: No, hits=-3.4, required=5.0,
tests=ALL_TRUSTED,AWL,BAYES_00,NO_REAL_NAME
Plugin spamassassin, hook data_post returned DECLINED,
running plugin (data_post): spamassassin
spamassassin plugin: check_spam_reject: reject_threshold=20
spamassassin plugin: check_spam_reject: score=-3.4
spamassassin plugin: check_spam_reject: passed
Plugin spamassassin, hook data_post returned DECLINED,
running plugin (queue): queue::qmail_2dqueue
queue::qmail_2dqueue plugin: (for 25227 ) Queuing qp 25230 to
/var/qmail/bin/qmail-queue
Plugin queue::qmail_2dqueue, hook queue returned OK, Queued! 1140396187
qp 25230 <>
250 Queued! 1140396187 qp 25230 <>
--> running plugin (reset_transaction): logging::trilog
--> Plugin logging::trilog, hook reset_transaction returned DONE,
dispatching QUIT
running plugin (quit): quit_fortune
Plugin quit_fortune, hook quit returned DECLINED,
trying to get config for me
221 batmobile.robinbowes.com closing connection. Have a wonderful day.
click, disconnecting
running plugin (disconnect): dnsbl
Plugin dnsbl, hook disconnect returned DECLINED,
--> running plugin (reset_transaction): logging::trilog
--> Plugin logging::trilog, hook reset_transaction returned DONE,
I've highlighted the three occassions where reset_transation is called
with "--> "
My question is:
1. Is this normal? i.e. is it correct that this is getting called three
times?
2. If it is normal, how to I detect the final time it is called as I
only want to log the accepted mail details once? i.e. what changes
between calls to reset_transaction?
Thanks,
R.
