Revision control
Copy as Markdown
#!/usr/bin/env perl
use 5.010;
use strict;
use warnings;
use utf8;
=head1 NAME
15-testrunner-capture-logs.t - tests for testrunner.pl's log capturing
=head1 SYNOPSIS
perl ./15-testrunner-capture-logs.t [--debug]
This test will run the testrunner.pl script with various types of logging
from subprocesses, verifying that the logs are captured correctly.
If --debug is given, temporary files are left behind for inspection after
the test completes.
=cut
use Capture::Tiny qw( capture );
use Carp;
use Encode qw( encode_utf8 );
use English qw( -no_match_vars );
use File::Path qw( rmtree );
use File::Slurp qw( read_file );
use File::Spec::Functions;
use File::Temp qw( tempdir );
use FindBin;
use Getopt::Long;
use IO::Handle;
use Readonly;
use Test::More;
use Time::HiRes qw( sleep );
use lib "$FindBin::Bin/../../lib/perl5";
use QtQA::Test::More qw( is_or_like );
Readonly my $WINDOWS => ($OSNAME =~ m{mswin32}i);
# Directory containing some helper scripts
Readonly my $HELPER_DIR => catfile( $FindBin::Bin, 'helpers' );
# Stream markers for use in TEST_OUTPUT
Readonly my $STREAM_OUTPUT => 1; # well-behaved output, to stdout or to -o testlog
Readonly my $STREAM_ERROR => 2; # standard error
Readonly my $STREAM_OUTPUT_STDOUT => 3; # badly behaved output, goes to stdout even in -o mode
# Various test texts we can output
Readonly my %TEST_OUTPUT => (
mixed => [
$STREAM_OUTPUT => "1:testlog\n2:testlog\n",
$STREAM_ERROR => "1:stderr\n2:stderr\n",
$STREAM_OUTPUT_STDOUT => "1:stdout\n2:stdout\n",
$STREAM_OUTPUT_STDOUT => "3:stdout\n4:stdout\n",
$STREAM_ERROR => "3:stderr\n4:stderr\n",
$STREAM_OUTPUT => "3:testlog\n4:testlog\n",
],
mixed_nonascii => [
$STREAM_OUTPUT => encode_utf8( "1:testlog:早上好\n2:testlog:你好马？\n" ),
$STREAM_ERROR => encode_utf8( "1:stderr:早上好\n2:stderr:你好马？\n" ),
$STREAM_OUTPUT_STDOUT => encode_utf8( "1:stdout:早上好\n2:stdout:你好马？\n" ),
$STREAM_OUTPUT_STDOUT => encode_utf8( "3:stdout:早上好\n4:stdout:你好马？\n" ),
$STREAM_ERROR => encode_utf8( "3:stderr:早上好\n4:stderr:你好马？\n" ),
$STREAM_OUTPUT => encode_utf8( "3:testlog:早上好\n4:testlog:你好马？\n" ),
],
);
# Command used to output the above and handle `-o somefile' in testlib-compatible way
Readonly my @TEST_COMMAND => (
'perl', # force `perl', not `$EXECUTABLE_NAME', as test log naming depends on it
"-I$FindBin::Bin/../../lib/perl5",
'-e',
"do q{$0} || die; run_from_subprocess( )", # call run_from_subprocess in this file
'--', # tell perl interpreter not to handle any more args
);
# Testrunner script
Readonly my @TESTRUNNER => (
$EXECUTABLE_NAME,
"$FindBin::Bin/../testrunner.pl",
);
# Whether or not we appear to have superuser permissions (used to skip one test)
Readonly my $IS_SUPERUSER
=> ($EFFECTIVE_USER_ID == 0) # unix: are we root?
|| $WINDOWS # windows: no sane way to tell for now, so be safe
# and always act like we're an admin
|| ($OSNAME =~ m{darwin}i) # mac: users other than root may have elevated
# permissions, so play it safe
;
# Pattern matching --verbose 'begin' line, without trailing \n.
Readonly my $TESTRUNNER_VERBOSE_BEGIN
=> qr{\QQtQA::App::TestRunner: begin \E.*?:\Q [perl]\E[^\n]*};
# Pattern matching --verbose 'end' line, without trailing \n.
# Ends with [^\n]*, so it can match or not match the exit status portion,
# as appropriate.
Readonly my $TESTRUNNER_VERBOSE_END
=> qr{\QQtQA::App::TestRunner: end \E[^:]+\Q: \E[^\n]*};
# Returns expected error text when a nonexistent $cmd is run
sub error_nonexistent_command
{
my ($cmd) = @_;
# Note subtle difference here: on Unix, it is QtQA::App::TestRunner who
# determines that the command doesn't exist. On Windows, there is always
# an intermediate cmd.exe (due to the way system() works on Windows), and
# that process is the one who determines that the command doesn't exist.
if ($WINDOWS) {
return "'$cmd' is not recognized as an internal or external command,\n"
."operable program or batch file.\n";
}
return "QtQA::App::TestRunner: $cmd: No such file or directory\n";
}
# Do a test run for a single dataset.
#
# Parameters:
# a single hashref, with keys (all optional):
# command => command to run (defaults to @TEST_COMMAND)
# command_args => arrayref of extra args to pass to command (defaults to nothing)
# testname => test name passed into Test::More functions
# testrunner_args => arrayref of extra args to pass to testrunner
# expected_success => 0 if testrunner is expected to fail (non-zero exit code)
# expected_stdout => expected standard output of subprocess (text or regex)
# expected_stderr => expected standard error of subprocess (text or regex)
# expected_logfile => expected log file which should be created by subprocess (if any)
# expected_logtext => expected content of the above logfile (text or regex)
#
sub run_one_test
{
my ($arg_ref) = @_;
my @command = @{$arg_ref->{ command } // \@TEST_COMMAND};
my @command_args = @{$arg_ref->{ command_args } // []};
my @testrunner_args = @{$arg_ref->{ testrunner_args } // ['--']};
my $expected_success = $arg_ref->{ expected_success } // 1;
my $expected_stdout = $arg_ref->{ expected_stdout } // "";
my $expected_stderr = $arg_ref->{ expected_stderr } // "";
my $expected_logfile = $arg_ref->{ expected_logfile };
my $expected_logtext = $arg_ref->{ expected_logtext } // "";
my $testname = $arg_ref->{ testname };
my @expected_logfiles
= $arg_ref->{ expected_logfiles } ? @{ $arg_ref->{ expected_logfiles } }
: $expected_logfile ? ( $expected_logfile )
: ();
my @expected_logtexts
= $arg_ref->{ expected_logtexts } ? @{ $arg_ref->{ expected_logtexts } }
: $expected_logtext ? ( $expected_logtext )
: ();
if (scalar(@expected_logfiles) != scalar(@expected_logtexts)) {
die 'test error: expected_logfiles and expected_logtexts count do not match!';
}
foreach my $logfile (@expected_logfiles) {
# Ensure the log file doesn't exist prior to the test (should "never" happen)
ok( ! -e $logfile, "$testname $logfile doesn't exist prior to test" );
}
my $status;
my ($stdout, $stderr) = capture {
$status = system( @TESTRUNNER, @testrunner_args, @command, @command_args );
};
if ($expected_success) {
is( $status, 0, "$testname exited with zero exit code" );
}
else {
isnt( $status, 0, "$testname exited with non-zero exit code" );
}
is_or_like( $stdout, $expected_stdout, "$testname stdout is as expected" );
is_or_like( $stderr, $expected_stderr, "$testname stderr is as expected" );
# The rest of the verification steps are only applicable if a log file is expected and created
return if (!@expected_logfiles);
my $i = 0;
foreach my $logfile (@expected_logfiles) {
return if (!ok( -e $logfile, "$testname created $logfile" ));
my $logtext = read_file( $logfile ); # dies on error
is_or_like( $logtext, $expected_logtexts[$i], "$testname $logfile logtext is as expected" );
++$i;
}
return;
}
#============================== subprocess parts ==================================================
# These are never called in the main test process, they are called by `perl -e' subprocesses
# Open and return a writable FH to the specified $filename (which may be - for STDOUT)
sub open_log_fh
{
my ($filename) = @_;
if ($filename eq '-') {
return IO::Handle->new_from_fd(fileno(STDOUT), 'w') || confess "internal error: open STDOUT for write: $!";
}
open( my $out, '>', $filename ) || confess "internal error: open $filename for write: $!";
return $out;
}
# Iterate through a set of testdata and print each chunk to the correct stream.
#
# Parameters:
# a hashref with the following keys:
# content => test data array (a value from %TEST_OUTPUT)
# filename => the file to be used as a log file (or - for STDOUT)
#
sub print_testdata
{
my ($arg_ref) = @_;
my $content = $arg_ref->{ content };
my $filename = $arg_ref->{ filename };
my $log_fh = open_log_fh( $filename );
# $content is an arrayref of (stream, text) pairs, which determine what
# text is printed and to which stream(s). For example:
#
# [
# $STREAM_STDOUT => 'This line should be printed to STDOUT',
# $STREAM_STDERR => 'This line should be printed to STDERR',
# ]
#
my @text_chunks = @{$content};
while (@text_chunks) {
my $stream = shift @text_chunks;
my $text = shift @text_chunks;
confess 'internal error: odd number of elements in testdata' if (! defined $text);
# These prints are all flushed to ensure that line ordering is correct in the case
# where $log_fh is another handle to STDOUT or STDERR.
if ($stream == $STREAM_OUTPUT) {
$log_fh->printflush( $text );
}
elsif ($stream == $STREAM_ERROR) {
STDERR->printflush( $text );
}
elsif ($stream == $STREAM_OUTPUT_STDOUT) {
STDOUT->printflush( $text );
}
else {
confess "internal error: bad test stream $stream in testdata";
}
# This is effectively a yield to the parent process, to give it a chance to read
# our output one line at a time. If we don't do this, we may easily fill up both
# the buffers in the parent connected to our stdout/stderr, and information about
# the order is lost.
sleep 0.05;
}
close( $log_fh ) || confess "internal error: close $filename after write: $!";
return;
}
# Primary entry point for test subprocess.
sub run_from_subprocess
{
my $exitcode = 0;
my @output_filenames;
my $output_content;
my $skip_log;
GetOptions(
'o=s' => \@output_filenames,
'maxwarnings=s' => sub {}, # don't care, just emulating testlib
'exitcode=i' => \$exitcode,
'skip-log' => \$skip_log,
) || die;
# If skiplog is set, we ignore the -o option, to simulate a badly behaved test
# which has been passed -o but ignored it (e.g. because QTest::qExec was used
# incorrectly).
if ($skip_log) {
@output_filenames = ('-');
}
if (!@output_filenames) {
@output_filenames = ('-');
}
$output_content = shift @ARGV;
confess 'internal error: not enough arguments'
if (!$output_content);
confess "internal error: `$output_content' is not valid testdata"
if (!$TEST_OUTPUT{$output_content});
foreach my $filename_and_format (@output_filenames) {
my $filename;
my $format;
if ($filename_and_format =~ m{,}) {
($filename, $format) = split(/,/, $filename_and_format);
}
else {
$filename = $filename_and_format;
}
my $content = $TEST_OUTPUT{$output_content};
# When printing more than one log, prefix with the format,
# to verify that we're really getting the right log in the right place.
if ($format) {
$content = [
$STREAM_OUTPUT => "format:$format\n",
@{ $content },
];
}
print_testdata({
content => $content,
filename => $filename,
});
}
exit $exitcode;
}
#==================================================================================================
# Calculate a set of regular expressions to match sequences of lines.
#
# Input: a list of arrayrefs, each containing a sequence of lines (strings or regular expressions,
# _without_ trailing \n)
#
# Returns: an arrayref containing a set of regular expressions. Some text satisfies _all_ the
# line sequences only if _all_ the regular expressions match.
#
# The primary use case for this function is to match the output of commands/logs where
# both STDOUT and STDERR should be separately checked. In this case, there are multiple output
# streams, and the order of output from each stream can be guaranteed but the order of output
# _between_ streams cannot.
#
# Example:
#
# my $rx = rx_for_lines(
# [
# "stdout line one",
# "stdout line two",
# ],
# [
# "stderr line one",
# "stderr line two",
# ],
# );
# is_or_like( $some_text, $rx );
#
# In this example, is_or_like will pass only if the following is true:
#
# - $some_text contains exactly 4 lines of output
# - $some_text contains both "stdout line one\n" and "stdout line two\n", in that order
# - $some_text contains both "stderr line one\n" and "stderr line two\n", in that order
#
# The comparison will succeed regardless of the order of stdout/stderr interleaving
# (as long as line-based flushing was used on stdout/stderr).
#
sub rx_for_lines
{
my (@line_refs) = @_;
my @out;
my $line_count = 0;
foreach my $lines (@line_refs) {
my @rx_lines = map {
if (ref($_) eq 'Regexp') {
"$_";
} else {
quotemeta($_).'\n'
}
} @{$lines};
$line_count += scalar( @rx_lines );
my $rx;
# First line
$rx .= q{
(?: # First line may appear in two cases:
\A # (1) very first line in the text
|
\n # (2) not the first line in the text
)
};
# Rest of lines
$rx .= join( q{
.*? # 0 or more of any character between lines
(?<=\n) # lines must follow a \n (but that must not be consumed, because
# it may be the \n at the end of the previously matched line)
}, @rx_lines );
push @out, qr{$rx}xms;
}
# The above regular expressions ensure we get all lines in the correct order.
# Finally, add an rx to make sure we got exactly the correct amount of lines.
push @out, qr/
\A # beginning ...
(?: [^\n]* \n ){$line_count} # exactly $line_count newline characters
[^\n]* # maybe some other stuff between last \n and end of text
\z # end
/xms;
return \@out;
}
# Primary entry point for the test.
sub run
{
my $debug;
GetOptions(
'debug' => \$debug,
) || die;
my $tempdir = tempdir( 'qtqa-test-capture-logs.XXXXXX', TMPDIR => 1, CLEANUP => !$debug );
if ($debug) {
diag( "Using $tempdir as temporary directory" );
}
###############################################################################################
# Basic controls to ensure output is correct when there is no capturing
run_one_test({
testname => 'mixed no capturing failing',
command_args => [ '--exitcode', 2, 'mixed' ],
expected_stdout =>
"1:testlog\n2:testlog\n"
."1:stdout\n2:stdout\n"
."3:stdout\n4:stdout\n"
."3:testlog\n4:testlog\n"
,
expected_stderr =>
"1:stderr\n2:stderr\n"
."3:stderr\n4:stderr\n"
,
expected_success => 0,
});
run_one_test({
testname => 'mixed_nonascii no capturing',
command_args => [ 'mixed_nonascii' ],
expected_stdout => encode_utf8(
"1:testlog:早上好\n2:testlog:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."3:testlog:早上好\n4:testlog:你好马？\n"
),
expected_stderr => encode_utf8(
"1:stderr:早上好\n2:stderr:你好马？\n"
."3:stderr:早上好\n4:stderr:你好马？\n"
),
});
###############################################################################################
# Test simple capture error cases without -o
SKIP: {
skip( 'unsafe to run this test as superuser', 1 ) if ($IS_SUPERUSER);
# We've assumed that /some_notexist_dir:
# - does not exist, and
# - cannot be created by testrunner (because we're not superuser)
#
run_one_test({
testname => 'mixed, capture error',
testrunner_args => [ '--capture-logs', '/some_notexist_dir', '--'],
command_args => [ 'mixed' ],
expected_stderr => qr{\Amkdir /some_notexist_dir: Permission denied}ms,
expected_success => 0,
});
}
###############################################################################################
# Test regular capture without -o;
# since -o is not used, it should capture everything
rmtree( $tempdir ); # testrunner should create the logdir if necessary
run_one_test({
testname => 'mixed_nonascii with capture',
testrunner_args => [ '--capture-logs', $tempdir, '--'],
command_args => [ '--exitcode', 3, 'mixed_nonascii' ],
expected_success => 0,
expected_logfile => "$tempdir/perl-00.txt",
expected_logtext => rx_for_lines(
[map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
3:testlog:早上好
4:testlog:你好马？
)],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
),
});
run_one_test({
testname => 'mixed_nonascii with tee',
testrunner_args => [ '--tee-logs', $tempdir, '--'],
command_args => [ 'mixed_nonascii' ],
expected_logfile => "$tempdir/perl-01.txt", # we didn't clean up, so a new filename is used
# tee, so stdout and stderr are both captured, and printed:
expected_stdout => encode_utf8(
"1:testlog:早上好\n2:testlog:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."3:testlog:早上好\n4:testlog:你好马？\n"
),
expected_stderr => encode_utf8(
"1:stderr:早上好\n2:stderr:你好马？\n"
."3:stderr:早上好\n4:stderr:你好马？\n"
),
expected_logtext => rx_for_lines(
[map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
3:testlog:早上好
4:testlog:你好马？
)],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
),
});
run_one_test({
testname => 'mixed with capture',
testrunner_args => [ '--sync-output', '--verbose', '--capture-logs', $tempdir, '--'],
command_args => [ 'mixed' ],
expected_logfile => "$tempdir/perl-02.txt",
expected_logtext => rx_for_lines(
[
$TESTRUNNER_VERBOSE_BEGIN,
qw(
1:testlog
2:testlog
1:stdout
2:stdout
3:stdout
4:stdout
3:testlog
4:testlog
),
qr{$TESTRUNNER_VERBOSE_END, exit code 0},
],
[qw(
1:stderr
2:stderr
3:stderr
4:stderr
)],
),
});
###############################################################################################
# Test capture with the usage of -o;
# in this case, the test writes some of its stuff correctly to the log,
# but the stuff which instead goes directly to stdout/stderr will be appended to the end
# of the log by the testrunner.
rmtree( $tempdir );
run_one_test({
testname => 'mixed_nonascii with capture and verbose and -o',
testrunner_args => [ '--capture-logs', $tempdir, '--verbose', '--' ],
command_args => [ '--exitcode', 12, '-o', 'testlog.log', 'mixed_nonascii' ],
expected_success => 0,
# note the naming convention with -o is to reuse the basename and extension
expected_logfile => "$tempdir/perl-testlog-00.log",
expected_logtext => rx_for_lines(
[map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
3:testlog:早上好
4:testlog:你好马？
),
q{},
qq{QtQA::App::TestRunner: test output additional content directly to stdout/stderr:},
],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
[map { encode_utf8($_) } qw(
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
)],
),
# Known limitation: with --capture-logs and -o, these messages can't go to
# the captured log, because they may be printed before the test has created
# the log file.
expected_stderr => qr{
\A
$TESTRUNNER_VERBOSE_BEGIN \n
$TESTRUNNER_VERBOSE_END \Q, exit code 12\E\n
\z
}xms,
});
run_one_test({
testname => 'mixed with capture and -o',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.log', 'mixed' ],
expected_logfile => "$tempdir/perl-testlog-01.log",
expected_logtext => rx_for_lines(
[qw(
1:testlog
2:testlog
3:testlog
4:testlog
),
q{},
qq{QtQA::App::TestRunner: test output additional content directly to stdout/stderr:},
],
[qw(
1:stderr
2:stderr
3:stderr
4:stderr
)],
[qw(
1:stdout
2:stdout
3:stdout
4:stdout
)],
),
});
run_one_test({
testname => 'mixed with capture and -o and tee',
testrunner_args => [ '--sync-output', '--tee-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.log', 'mixed' ],
expected_logfile => "$tempdir/perl-testlog-02.log",
expected_logtext => rx_for_lines(
[qw(
1:testlog
2:testlog
3:testlog
4:testlog
),
q{},
qq{QtQA::App::TestRunner: test output additional content directly to stdout/stderr:},
],
[qw(
1:stderr
2:stderr
3:stderr
4:stderr
)],
[qw(
1:stdout
2:stdout
3:stdout
4:stdout
)],
),
# because we used --sync-output, stdout and stderr are merged
expected_stdout =>
"1:stderr\n2:stderr\n"
."1:stdout\n2:stdout\n"
."3:stdout\n4:stdout\n"
."3:stderr\n4:stderr\n"
,
});
###############################################################################################
# Capture with the new testlib simultaneous loggers.
# If we capture with:
#
# -o file1,fmt1 -o file2,fmt2 -o -,fmt3
#
# ... then the testrunner should capture file1 and file2, but should pass through the third
# stream (fmt3) to stdout as normal. stderr is also passed through uncaptured.
#
run_one_test({
testname => 'mixed_nonascii new style -o, capture, multiple logs',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.xml,xml', '-o', 'testlog.xunitxml,xunitxml', '-o', '-,txt', 'mixed_nonascii' ],
expected_logfiles => [ "$tempdir/perl-testlog-00.xml", "$tempdir/perl-testlog-00.xunitxml" ],
expected_logtexts => [
# first log: xml format
encode_utf8(
"format:xml\n"
."1:testlog:早上好\n"
."2:testlog:你好马？\n"
."3:testlog:早上好\n"
."4:testlog:你好马？\n"
),
# second log: xunitxml format
encode_utf8(
"format:xunitxml\n"
."1:testlog:早上好\n"
."2:testlog:你好马？\n"
."3:testlog:早上好\n"
."4:testlog:你好马？\n"
),
],
expected_stdout => encode_utf8(
# we get the first portion of stdout also from the first two loggers
"1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."format:txt\n"
."1:testlog:早上好\n2:testlog:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."3:testlog:早上好\n4:testlog:你好马？\n"
),
expected_stderr => encode_utf8(
(
"1:stderr:早上好\n2:stderr:你好马？\n"
."3:stderr:早上好\n4:stderr:你好马？\n"
) x 3 # three loggers, so printed three times
),
});
###############################################################################################
# Tee with the new testlib simultaneous loggers.
# If we tee with:
#
# -o file1,fmt1 -o file2,fmt2 -o -,fmt3
#
# ... the behavior is exactly the same as capture-logs.
# It is explicitly documented that tee-logs and capture-logs is the same thing in the
# multi-logger case, since testlib already is implementing the tee-like behavior.
#
run_one_test({
testname => 'mixed_nonascii new style -o, tee, multiple logs, one stdout',
testrunner_args => [ '--tee-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.xml,xml', '-o', 'testlog.txt,txt', '-o', '-,txt', 'mixed_nonascii' ],
expected_logfiles => [ "$tempdir/perl-testlog-01.xml", "$tempdir/perl-testlog-00.txt" ],
expected_logtexts => [
# first log: xml format, non-log text is not captured
encode_utf8(
"format:xml\n"
."1:testlog:早上好\n"
."2:testlog:你好马？\n"
."3:testlog:早上好\n"
."4:testlog:你好马？\n"
),
# second log: text format, non-log text is not captured
encode_utf8(
"format:txt\n"
."1:testlog:早上好\n"
."2:testlog:你好马？\n"
."3:testlog:早上好\n"
."4:testlog:你好马？\n"
),
],
expected_stdout => encode_utf8(
# we get the first portion of stdout also from the first two loggers
"1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."format:txt\n"
."1:testlog:早上好\n2:testlog:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."3:testlog:早上好\n4:testlog:你好马？\n"
),
expected_stderr => encode_utf8(
(
"1:stderr:早上好\n2:stderr:你好马？\n"
."3:stderr:早上好\n4:stderr:你好马？\n"
) x 3 # three loggers, so printed three times
),
});
###############################################################################################
# Make sure the options parser doesn't get tricked by bizarre options like
# `-maxwarnings -o somefile', where -o is a value and not an option
run_one_test({
testname => 'mixed_nonascii with capture and tricky arguments',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '--exitcode', 50, '-maxwarnings', '-o', 'mixed_nonascii' ],
expected_success => 0,
expected_logfile => "$tempdir/perl-00.txt",
# despite appearances, there was no -o option, so we expect a "raw" capture of everything
expected_logtext => rx_for_lines(
[map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
3:testlog:早上好
4:testlog:你好马？
)],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
),
});
run_one_test({
testname => 'mixed with capture and tricky arguments',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '-maxwarnings', '-o', 'mixed' ],
expected_logfile => "$tempdir/perl-01.txt",
expected_logtext => rx_for_lines(
[qw(
1:testlog
2:testlog
1:stdout
2:stdout
3:stdout
4:stdout
3:testlog
4:testlog
)],
[qw(
1:stderr
2:stderr
3:stderr
4:stderr
)],
),
});
###############################################################################################
# test capture when -o is passed to test, but is ignored (badly behaved test)
rmtree( $tempdir );
run_one_test({
testname => 'mixed with capture and ignored -o',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.log', '--skip-log', 'mixed' ],
expected_success => 0, # failure should be forced even though exit code of test is 0
expected_logfile => "$tempdir/perl-testlog-00.log",
expected_logtext => rx_for_lines(
[
q{Log file created by QtQA::App::TestRunner},
q{},
q{QtQA::App::TestRunner: FAIL! Test was badly behaved, the `-o' argument was ignored.},
q{QtQA::App::TestRunner: stdout/stderr follows:},
qw(
1:testlog
2:testlog
1:stdout
2:stdout
3:stdout
4:stdout
3:testlog
4:testlog
)
],
[qw(
1:stderr
2:stderr
3:stderr
4:stderr
)],
),
});
run_one_test({
testname => 'mixed_nonascii with capture and ignored -o',
testrunner_args => [ '--capture-logs', $tempdir, '--' ],
command_args => [ '--exitcode', 23, '-o', 'testlog.log.txt',
'--skip-log', 'mixed_nonascii' ],
expected_success => 0,
expected_logfile => "$tempdir/perl-testlog.log-00.txt",
expected_logtext => rx_for_lines(
[
q{Log file created by QtQA::App::TestRunner},
q{},
q{QtQA::App::TestRunner: FAIL! Test was badly behaved, the `-o' argument was ignored.},
q{QtQA::App::TestRunner: stdout/stderr follows:},
map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
3:testlog:早上好
4:testlog:你好马？
)
],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
),
});
run_one_test({
testname => 'mixed_nonascii with capture and ignored -o and tee',
testrunner_args => [ '--tee-logs', $tempdir, '--' ],
command_args => [ '-o', 'testlog.log.txt', '--skip-log', 'mixed_nonascii' ],
expected_logtext => rx_for_lines(
[
q{Log file created by QtQA::App::TestRunner},
q{},
q{QtQA::App::TestRunner: FAIL! Test was badly behaved, the `-o' argument was ignored.},
q{QtQA::App::TestRunner: stdout/stderr follows:},
map { encode_utf8($_) } qw(
1:testlog:早上好
2:testlog:你好马？
1:stdout:早上好
2:stdout:你好马？
3:stdout:早上好
4:stdout:你好马？
3:testlog:早上好
4:testlog:你好马？
)
],
[map { encode_utf8($_) } qw(
1:stderr:早上好
2:stderr:你好马？
3:stderr:早上好
4:stderr:你好马？
)],
),
expected_stdout => encode_utf8(
"1:testlog:早上好\n2:testlog:你好马？\n"
."1:stdout:早上好\n2:stdout:你好马？\n"
."3:stdout:早上好\n4:stdout:你好马？\n"
."3:testlog:早上好\n4:testlog:你好马？\n"
),
expected_stderr => encode_utf8(
"1:stderr:早上好\n2:stderr:你好马？\n"
."3:stderr:早上好\n4:stderr:你好马？\n"
),
expected_logfile => "$tempdir/perl-testlog.log-01.txt",
expected_success => 0,
});
###############################################################################################
# test that Proc::Reliable errors are correctly captured/teed
rmtree( $tempdir );
run_one_test({
testname => 'capture error nonexistent process',
testrunner_args => [ '--capture-logs', $tempdir, '--'],
command => [ 'command_which_does_not_exist' ],
expected_logfile => "$tempdir/command_which_does_not_exist-00.txt",
expected_logtext => error_nonexistent_command('command_which_does_not_exist'),
expected_stderr => "",
expected_success => 0,
});
run_one_test({
testname => 'tee error nonexistent process',
testrunner_args => [ '--tee-logs', $tempdir, '--'],
command => [ 'command_which_does_not_exist' ],
expected_logfile => "$tempdir/command_which_does_not_exist-01.txt",
expected_logtext => error_nonexistent_command('command_which_does_not_exist'),
expected_stderr => error_nonexistent_command('command_which_does_not_exist'),
expected_success => 0,
});
my $crash_script = catfile( $HELPER_DIR, 'dereference_bad_pointer.pl' );
my $crash_rx = ($WINDOWS)
? "QtQA::App::TestRunner: Process exited with exit code 0xC0000005 (STATUS_ACCESS_VIOLATION)\n"
: qr{\AQtQA::App::TestRunner: Process exited due to signal 11(; dumped core)?\n\z}ms;
run_one_test({
testname => 'capture error crashing',
testrunner_args => [ '--capture-logs', $tempdir, '--'],
command => [ 'perl', $crash_script ],
expected_logfile => "$tempdir/perl-00.txt",
expected_logtext => $crash_rx,
expected_stderr => "",
expected_success => 0,
});
run_one_test({
testname => 'tee error crashing',
testrunner_args => [ '--tee-logs', $tempdir, '--'],
command => [ 'perl', $crash_script ],
expected_logfile => "$tempdir/perl-01.txt",
expected_logtext => $crash_rx,
expected_stderr => $crash_rx,
expected_success => 0,
});
done_testing( );
return;
}
run if (!caller);
1;