2012-04-29 10:35:59 +02:00
|
|
|
#!perl -w
|
2009-03-02 19:53:33 +01:00
|
|
|
|
|
|
|
=head1 NAME
|
|
|
|
|
2012-05-21 05:04:36 +02:00
|
|
|
connection_time - log the duration of a connection
|
2009-03-02 19:53:33 +01:00
|
|
|
|
|
|
|
=head1 DESCRIPTION
|
|
|
|
|
|
|
|
The B<connection_time> plugin records the time of a connection between the
|
2012-05-21 05:04:36 +02:00
|
|
|
first and the last possible hook in qpsmtpd (I<pre-connection> and
|
|
|
|
I<post-connection>) and writes a C<LOGINFO> (default, see below) line to
|
2009-03-02 19:53:33 +01:00
|
|
|
the log.
|
|
|
|
|
|
|
|
=head1 CONFIG
|
|
|
|
|
2012-05-21 05:04:36 +02:00
|
|
|
=head2 loglevel
|
|
|
|
|
|
|
|
Adjust the quantity of logging for this plugin. See docs/logging.pod
|
|
|
|
|
|
|
|
connection_time loglevel +1 (less logging)
|
|
|
|
|
|
|
|
connection_time loglevel -1 (more logging)
|
2009-03-02 19:53:33 +01:00
|
|
|
|
|
|
|
=cut
|
|
|
|
|
2012-05-21 05:04:36 +02:00
|
|
|
use strict;
|
|
|
|
use warnings;
|
|
|
|
|
2009-03-02 19:53:33 +01:00
|
|
|
use Qpsmtpd::Constants;
|
|
|
|
|
2012-06-04 03:39:32 +02:00
|
|
|
use Time::HiRes qw(gettimeofday tv_interval);
|
|
|
|
|
2009-03-02 19:53:33 +01:00
|
|
|
sub register {
|
2012-06-23 06:40:02 +02:00
|
|
|
my ($self, $qp) = (shift, shift);
|
2013-04-21 06:50:39 +02:00
|
|
|
if (@_ == 1) { # backwards compatible
|
2012-05-21 05:04:36 +02:00
|
|
|
$self->{_args}{loglevel} = shift;
|
2013-04-21 06:50:39 +02:00
|
|
|
if ($self->{_args}{loglevel} =~ /\D/) {
|
|
|
|
$self->{_args}{loglevel} =
|
|
|
|
Qpsmtpd::Constants::log_level($self->{_args}{loglevel});
|
|
|
|
}
|
2012-05-21 05:04:36 +02:00
|
|
|
$self->{_args}{loglevel} ||= 6;
|
|
|
|
}
|
2013-04-21 06:50:39 +02:00
|
|
|
elsif (@_ % 2) {
|
|
|
|
$self->log(LOGERROR, "invalid arguments");
|
2012-05-21 05:04:36 +02:00
|
|
|
}
|
|
|
|
else {
|
2013-04-21 06:50:39 +02:00
|
|
|
$self->{_args} = {@_}; # named args, inherits loglevel
|
|
|
|
}
|
|
|
|
|
|
|
|
# pre-connection is not available in the tcpserver deployment model.
|
|
|
|
# duplicate the handler, so it works both ways with no redudant methods
|
2012-06-23 06:40:02 +02:00
|
|
|
$self->register_hook('pre-connection', 'connect_handler');
|
|
|
|
$self->register_hook('connect', 'connect_handler');
|
2009-03-02 19:53:33 +01:00
|
|
|
}
|
|
|
|
|
2012-06-23 06:40:02 +02:00
|
|
|
sub connect_handler {
|
2012-06-04 03:39:32 +02:00
|
|
|
my $self = shift;
|
2013-04-21 06:50:39 +02:00
|
|
|
return DECLINED
|
|
|
|
if ($self->hook_name eq 'connect' && defined $self->{_connection_start});
|
2012-06-04 03:39:32 +02:00
|
|
|
$self->{_connection_start} = [gettimeofday];
|
2013-04-21 06:50:39 +02:00
|
|
|
$self->log(LOGDEBUG, "started at " . scalar gettimeofday);
|
2014-09-18 03:28:51 +02:00
|
|
|
return DECLINED;
|
2009-03-02 19:53:33 +01:00
|
|
|
}
|
|
|
|
|
|
|
|
sub hook_post_connection {
|
2012-06-04 03:39:32 +02:00
|
|
|
my $self = shift;
|
2012-05-21 05:04:36 +02:00
|
|
|
|
2013-04-21 06:50:39 +02:00
|
|
|
if (!$self->{_connection_start}) {
|
2012-05-21 05:04:36 +02:00
|
|
|
$self->log(LOGERROR, "Start time not set?!");
|
2014-09-18 03:28:51 +02:00
|
|
|
return DECLINED;
|
2013-04-21 06:50:39 +02:00
|
|
|
}
|
2012-05-21 05:04:36 +02:00
|
|
|
|
2013-04-21 06:50:39 +02:00
|
|
|
my $elapsed = tv_interval($self->{_connection_start}, [gettimeofday]);
|
2012-05-21 05:04:36 +02:00
|
|
|
|
2013-04-21 06:50:39 +02:00
|
|
|
$self->log(LOGINFO, sprintf "%.3f s.", $elapsed);
|
2014-09-18 03:28:51 +02:00
|
|
|
return DECLINED;
|
2009-03-02 19:53:33 +01:00
|
|
|
}
|