Revision control
++ #!/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;