Strategy for conditional logging in tests

[andreas1234567]

I use Log::Log4perl for logging, and Test::More and Test::Exception for testing. I write a number of negative tests (e.g. to see if a module reacts correctly when given incorrect input), and the output from these tests can be very verbose. This means the unexpected error messages (if any) will be far outnumbered by the expected ones, thus harder to detect when reading the output.

I'm looking for a strategy on how to suppress output from negative tests (warnings, output from die etc.), while keeping the output enabled for the positive tests (where output is unexpected and might indicate a problem).

The dilemma is probably best shown with an example:

foo.pl

# foo.pl
use strict;
use warnings;
use Log::Log4perl;

my $conf = qq(
  log4perl.category.Script                 = INFO, ScreenAppender
  log4perl.appender.ScreenAppender         = Log::Log4perl::Appender::
+Screen
  log4perl.appender.ScreenAppender.layout  = PatternLayout
  log4perl.appender.ScreenAppender.layout.ConversionPattern=[%p] %d %M
+ %F:%L - %m%n
);

Log::Log4perl::init( \$conf );
my $log = Log::Log4perl::->get_logger(q(Script));

# Add two numbers, no larger than 32 each
sub add {
  my ($i, $j) = @_;
  $log->logdie("type error") unless ($i and $j and $i =~ m/^\d+/ and $
+j =~ m/^\d+/);
  $log->warn("possible overflow") unless ($i < 2**5 and $j < 2**5);
  return $i + $j;
}

# When testing: Disable all logging,
# When not testing: call add()
caller() ? Log::Log4perl->appender_thresholds_adjust(7) : print add(@A
+RGV);

1;
__END__

foo.t

# foo.t
use strict;
use warnings;

use Test::More qw/no_plan/;
use Test::Exception;

require_ok(q{foo.pl});

# ------ negative tests for add() ------
throws_ok { add(); } qr/error/i, q{Expect error when no args};
throws_ok { add('a'); } qr/error/i, q{Expect error with non-numeric in
+put};
throws_ok { add('a1'); } qr/error/i, q{Expect error with non-numeric i
+nput};
throws_ok { add(1,'b'); } qr/error/i, q{Expect error with non-numeric 
+input};
throws_ok { add(1,'b1'); } qr/error/i, q{Expect error with non-numeric
+ input};

# ------ positive tests for add() ------
cmp_ok(add(2,2), q{==}, 4, q{Expect 2+2=4});

# Note: I want a warning here:
cmp_ok(add(1000,1000), q{==}, 2000, q{Expect 1000+1000=2000});
__END__

Run

$ prove --version
TAP::Harness v3.10 and Perl v5.10.0
$ prove foo.t
foo......ok
All tests successful.
Files=1, Tests=8,  0 wallclock secs ( 0.02 usr  0.00 sys +  0.08 cusr 
+ 0.00 csys =  0.10 CPU)
Result: PASS

The above code takes an all-or-nothing approach to the logging, which results in the wanted possible overflow warning to be suppressed.

Do any of the Enlightened Monks have thoughts on how to selectively suppress output from tests?

[herveus]

Howdy!

If you put your subroutine in a .pm file, you can diddle the logging to appropriate levels in the .t and .pl files instead of having to do conditional hacks based on caller().

[andreas1234567]

I don't see that making it a module would make a difference. Please elaborate.

[Thilosophy]

I agree that having your code as a module or not does not make a big difference here, but you should be able to "diddle the logging to appropriate levels in the .t". Is it not possible to turn off logging from the test script for your negative tests, and then turn it back on for the others?

[wade]

You could try Expect or Expect::Simple. I've used tcl/Expect and it can be useful. The test is setup to look for the appropriate error messages -- any that are not generated or any new ones are flagged.