Hi,
I've recently upgraded my qpsmtpd to the most recent
0.83 release and hit a problem which had me stumped for
a while. In short plugins failed to get loaded, so
all incoming mail was refused with:
450 No plugin decided if relaying is allowed
Tracking this down was tricky, but ultimately it seems
the cause is the following section of Qpsmtpd.pm:
--
sub load_plugins
my @plugins = $self->config('plugins');
my @loaded;
if ($hooks->{queue}) {
print "Plugins loaded already\n";
use Data::Dumper;
print Dumper( \$hooks );
return @plugins;
}
--
Here we see the intent is to avoid loading plugins if they'd
already been loaded - that is done by looking to see if at
least one plugin has hooked queuing.
I added the Data::Dumper section, and updated _load_plugin to
log the loading of individual plugins:
--
sub _load_plugin {
my $self = shift;
my ($plugin_line, @plugin_dirs) = @_;
print "Load: $plugin_line\n";
--
When I launch qpsmtpd I see this:
--
lenny:/etc/qpsmtpd# /usr/bin/perl -Tw /usr/bin/qpsmtpd-prefork --port 25 --user
qpsmtpd --pid-file /var/run/qpsmtpd/qpsmtpd.pid --debug
26/10/2009 13:20:23:9059: qpsmtpd-prefork daemon, version: 1.0, staring on
host: 0.0.0.0:25 (user: qpsmtpd [0])
26/10/2009 13:20:23:9059: parent daemon nice level: -5
Load: logging/ffile:0 loglevel LOGCRIT /var/log/qpsmtpd/terse.log
Load: logging/terse
Load: logging/ffile:1 loglevel LOGINFO /var/log/qpsmtpd/qpsmtpd.log
Plugins loaded already
$VAR1 = \{
'logging' => [
{
'name' => 'logging::ffile_3a0',
'code' => sub { "DUMMY" }
},
{
'name' => 'logging::ffile_3a1',
'code' => sub { "DUMMY" }
}
],
'deny' => [
{
'name' => 'logging::terse',
'code' => sub { "DUMMY" }
}
],
'queue' => [
{
'name' => 'logging::terse',
'code' => sub { "DUMMY" }
}
],
'disconnect' => [
{
'name' => 'logging::ffile_3a0',
'code' => sub { "DUMMY" }
},
{
'name' => 'logging::ffile_3a1',
'code' => sub { "DUMMY" }
}
],
'connect' => [
{
'name' => 'logging::ffile_3a0',
'code' => sub { "DUMMY" }
},
{
'name' => 'logging::ffile_3a1',
'code' => sub { "DUMMY" }
}
]
};
26/10/2009 13:20:23:9059: new child, pid: 9060
26/10/2009 13:20:23:9059: new child, pid: 9061
--
In short because /etc/qpsmptd/logging contains "logterse" there
is a hook_queue installed, and this tricks the server into believing
that all the plugins are loaded even though only three plugins were
loaded. That means none of my "real" plugins are loaded, just the
logging ones and ultimately mail is refused for all recipients.
Having looked over the gitweb changelog I see nothing obvious
which could have caused this change in behaviour so I'm a little
stumped as to who is to "blame".
For the moment I've stopped using logterse and all is well.
I think it might be nice to update the code to test loading
in some other fashion - but first I thought I'd throw this out
to see if theres a sane explanation for this failure case.
Steve
--
Debian GNU/Linux System Administration
http://www.debian-administration.org/
