Merge pull request #221 from jaredj/run-continuation-logging-tests

Tests for error logging in run_continuation()
This commit is contained in:
Matt Simerson 2015-02-03 14:48:48 -08:00
commit b24f766cc5
3 changed files with 33 additions and 7 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

@ -148,19 +148,36 @@ sub __run_continuation {
disconnected => 0, disconnected => 0,
descr => 'DECLINED -> DENY', descr => 'DECLINED -> DENY',
}, },
# TODO: ignore invalid return codes rather than treating them like OK
#{
# hooks => [ [123456,undef], [DENY, 'goaway'] ],
# expected_response => '550/goaway',
# disconnected => 0,
# descr => 'INVALID -> DENY',
#},
{ {
hooks => [ [123456,undef], [DENY, 'goaway'] ], hooks => [ sub { die "dead\n" }, [DENY, 'begone'] ],
expected_response => '550/goaway', expected_response => '550/begone',
disconnected => 0, disconnected => 0,
descr => 'INVALID -> DENY', 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 ( @{ $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,8 +191,12 @@ 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 {