Tests for error logging in run_continuation()

This commit is contained in:
Jared Johnson 2015-02-03 16:18:45 -06:00
parent 7af1f770a5
commit b3f8ce6b07
3 changed files with 28 additions and 3 deletions

View File

@ -292,6 +292,7 @@ sub run_continuation {
my $tran = $self->transaction; my $tran = $self->transaction;
eval { @r = $code->{code}->($self, $tran, @$args); }; eval { @r = $code->{code}->($self, $tran, @$args); };
if ($@) { if ($@) {
chomp $@;
$self->log(LOGCRIT, "FATAL PLUGIN ERROR [$name]: ", $@); $self->log(LOGCRIT, "FATAL PLUGIN ERROR [$name]: ", $@);
next; next;
} }

View File

@ -96,7 +96,11 @@ sub log {
my ($self, $trace, $hook, $plugin, @log) = @_; my ($self, $trace, $hook, $plugin, @log) = @_;
my $level = Qpsmtpd::TRACE_LEVEL() || 5; my $level = Qpsmtpd::TRACE_LEVEL() || 5;
$level = $self->init_logger if !defined $level; $level = $self->init_logger if !defined $level;
print("# " . join(' ', $$, @log) . "\n") if $trace <= $level; return if $trace > $level;
print("# " . join(' ', $$, @log) . "\n");
( undef, undef, my @record_args ) = @_;
push @{ $self->{_logged} }, log_level($trace) . ":"
. join '', grep { defined } @record_args;
} }
sub varlog { sub varlog {

View File

@ -154,13 +154,29 @@ sub __run_continuation {
disconnected => 0, disconnected => 0,
descr => 'INVALID -> DENY', descr => 'INVALID -> DENY',
}, },
{
hooks => [ sub { die "dead\n" }, [DENY, 'begone'] ],
expected_response => '550/begone',
disconnected => 0,
logged => 'LOGCRIT:FATAL PLUGIN ERROR [___FakeHook___]: dead',
descr => 'fatal error -> DENY',
},
{
hooks => [ [undef], [DENY, 'nm'] ],
expected_response => '550/nm',
disconnected => 0,
logged => 'LOGERROR:Plugin ___FakeHook___, hook helo returned undef!',
descr => 'undef -> DENY',
},
); );
for my $t (@test_data) { for my $t (@test_data) {
for my $h ( reverse @{ $t->{hooks} } ) { for my $h ( reverse @{ $t->{hooks} } ) {
$smtpd->fake_hook( 'helo', sub { return @$h } ); my $sub = ( ref $h eq 'ARRAY' ? sub { return @$h } : $h );
$smtpd->fake_hook( 'helo', $sub );
} }
$smtpd->{_continuation} = [ 'helo', ['somearg'], @{ $smtpd->hooks->{helo} } ]; $smtpd->{_continuation} = [ 'helo', ['somearg'], @{ $smtpd->hooks->{helo} } ];
delete $smtpd->{_response}; delete $smtpd->{_response};
delete $smtpd->{_logged};
$smtpd->connection->notes( disconnected => undef ); $smtpd->connection->notes( disconnected => undef );
$smtpd->run_continuation; $smtpd->run_continuation;
my $response = join '/', @{ $smtpd->{_response} || [] }; my $response = join '/', @{ $smtpd->{_response} || [] };
@ -174,9 +190,13 @@ sub __run_continuation {
ok( ! $smtpd->connection->notes('disconnected'), ok( ! $smtpd->connection->notes('disconnected'),
"run_continuation() does not disconnect on $t->{descr}" ); "run_continuation() does not disconnect on $t->{descr}" );
} }
if ( $t->{logged} ) {
is( join("\n", @{ $smtpd->{_logged} || [] }), $t->{logged},
"run_continuation() logging on $t->{descr}" );
} }
$smtpd->unfake_hook('helo'); $smtpd->unfake_hook('helo');
} }
}
sub __hook_responder { sub __hook_responder {
my ($code, $msg) = $qp->hook_responder('test-hook', [OK,'test mesg']); my ($code, $msg) = $qp->hook_responder('test-hook', [OK,'test mesg']);