Revision control

++ #!/usr/bin/env perl
++ use 5.010;
++ use strict;
++ use warnings;
++
++ =head1 NAME
++
++ 21-testrunner-flaky.t - test testrunner's `flaky' plugin for unstable tests
++
++ =head1 SYNOPSIS
++
++ perl ./21-testrunner-flaky.t
++
++ This test will run the testrunner.pl script with some artificially unstable
++ processes and verify that the flaky plugin generates the expected output.
++
++ =cut
++
++ use Capture::Tiny qw( capture );
++ use English qw( -no_match_vars );
++ use File::Basename;
++ use File::Slurp qw( read_file );
++ use File::Temp qw( tempdir );
++ use FindBin;
++ use Readonly;
++ use Test::More;
++
++ use lib "$FindBin::Bin/../../lib/perl5";
++ use QtQA::Test::More qw( is_or_like );
++
++ # error from a stable failing test
++ Readonly my $ERROR_STABLE_FAILURE => <<'END_MESSAGE';
++ QtQA::App::TestRunner: test failed, running again to see if it is flaky...
++ QtQA::App::TestRunner: test failure could be reproduced twice consecutively
++ END_MESSAGE
++
++ # perl to simulate a test which fails, then succeeds.
++ Readonly my $PERL_VANISHING_FAILURE => <<'END_SCRIPT';
++ $|++;
++ if ($ENV{ QTQA_APP_TESTRUNNER_ATTEMPT } == 1) {
++ print qq{First attempt; failing...\n};
++ exit 13;
++ }
++ print qq{Second attempt; causing much vexation by passing!\n};
++ END_SCRIPT
++
++ # perl to simulate a test which eventually fails, then eventually succeeds.
++ Readonly my $PERL_VANISHING_FAILURE_TIMEOUT_WARNING => <<'END_SCRIPT';
++ sleep 2;
++ $|++;
++ if ($ENV{ QTQA_APP_TESTRUNNER_ATTEMPT } == 1) {
++ print qq{First attempt; failing...\n};
++ exit 13;
++ }
++ print qq{Second attempt; causing much vexation by passing!\n};
++ END_SCRIPT
++
++ # stdout from the above
++ Readonly my $OUTPUT_VANISHING_FAILURE => <<'END_MESSAGE';
++ First attempt; failing...
++ Second attempt; causing much vexation by passing!
++ END_MESSAGE
++
++ # error from the above
++ Readonly my $ERROR_VANISHING_FAILURE => <<'END_MESSAGE';
++ QtQA::App::TestRunner: test failed, running again to see if it is flaky...
++ QtQA::App::TestRunner: test failed on first attempt and passed on second attempt!
++ QtQA::App::TestRunner: first attempt: exited with exit code 13
++ QtQA::App::TestRunner: the test seems to be flaky, please fix this
++ END_MESSAGE
++
++ # above, in `pass' flaky mode
++ Readonly my $ERROR_VANISHING_FAILURE_MODE_BEST => $ERROR_VANISHING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a PASS
++ END_MESSAGE
++
++ # above, in `fail' flaky mode
++ Readonly my $ERROR_VANISHING_FAILURE_MODE_WORST => $ERROR_VANISHING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a FAIL
++ END_MESSAGE
++
++ # above, in `ignore' flaky mode
++ Readonly my $ERROR_VANISHING_FAILURE_MODE_IGNORE => $ERROR_VANISHING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being ignored
++ END_MESSAGE
++
++ # perl to simulate a test which fails by crashing, then succeeds.
++ Readonly my $PERL_VANISHING_CRASH => <<'END_SCRIPT';
++ $|++;
++ if ($ENV{ QTQA_APP_TESTRUNNER_ATTEMPT } == 1) {
++ print qq{First attempt; crashing...\n};
++ kill 11, $$;
++ }
++ print qq{Second attempt; causing much vexation by passing!\n};
++ END_SCRIPT
++
++ # stdout from the above
++ Readonly my $OUTPUT_VANISHING_CRASH => <<'END_MESSAGE';
++ First attempt; crashing...
++ Second attempt; causing much vexation by passing!
++ END_MESSAGE
++
++ # helper regexes for building up the larger regexes below
++ Readonly my $RE => {
++ flaky_first_fail => qr{
++ \QQtQA::App::TestRunner: test failed, running again to see if it is flaky...\E\n
++ }xms,
++
++ core_backtrace => qr{
++ \QQtQA::App::TestRunner: ============================== backtrace follows: ==============================\E \n
++ (?:QtQA::App::TestRunner: [^\n]+ \n)*
++ \QQtQA::App::TestRunner: Program terminated with signal \E(?:11|SIGSEGV)\Q, Segmentation fault.\E \n
++ (?:QtQA::App::TestRunner: [^\n]+ \n)*
++ \QQtQA::App::TestRunner: ================================================================================\E \n
++ }xms,
++
++ exited_with_signal11 => ($OSNAME =~ m{win32}i) ? qr{} : qr{
++ \QQtQA::App::TestRunner: Process exited due to signal 11; dumped core\E \n
++ }xms,
++
++ exited_with_any_signal => ($OSNAME =~ m{win32}i) ? qr{} : qr{
++ \QQtQA::App::TestRunner: Process exited due to signal \E \d+ (?:\Q; dumped core\E)? \n
++ }xms,
++
++ flaky_second_pass => qr{
++ \QQtQA::App::TestRunner: test failed on first attempt and passed on second attempt!\E \n
++ \QQtQA::App::TestRunner: first attempt: exited with signal 11\E \n
++ \QQtQA::App::TestRunner: the test seems to be flaky, please fix this\E \n
++ \QQtQA::App::TestRunner: this flaky test is being treated as a FAIL\E \n
++ }xms,
++
++ verbose_begin => qr{\QQtQA::App::TestRunner: begin \E.*?:\Q [perl]\E[^\n]*},
++ verbose_end => qr{\QQtQA::App::TestRunner: end \E[^:]+\Q: \E[^\n]*},
++ };
++
++ # perl to simulate a test which hangs (for 10 seconds)
++ Readonly my $PERL_HANGING_FAILURE => <<'END_SCRIPT';
++ $|++;
++ print qq{About to hang for a few seconds...\n};
++ sleep 10;
++ print qq{Still alive!?!? Most unexpected ...\n};
++ exit 0;
++ END_SCRIPT
++
++ # stdout from the above
++ Readonly my $OUTPUT_HANGING_FAILURE => <<'END_MESSAGE';
++ About to hang for a few seconds...
++ About to hang for a few seconds...
++ END_MESSAGE
++
++
++ # error from hanging test
++ Readonly my $ERROR_HANGING_FAILURE => qr|
++ \QQtQA::App::TestRunner: Timed out after \E \d+ \Q seconds\E \n
++ $RE->{ exited_with_any_signal }
++ \QQtQA::App::TestRunner: test failed, running again to see if it is flaky...\E \n
++ \QQtQA::App::TestRunner: Timed out after \E \d+ \Q seconds\E \n
++ $RE->{ exited_with_any_signal }
++ \QQtQA::App::TestRunner: test failure could be reproduced twice consecutively\E \n
++ |xms;
++
++ # error from the above (when using "flaky" and "core" plugins, in that order)
++ # note: hardcoded 3328 == (13 << 8)
++ Readonly my $ERROR_VANISHING_CRASH_WITH_FLAKY_AND_CORE => qr|
++ \A
++ $RE->{ exited_with_signal11 } # testrunner tells us that the test exited with signal 11...
++ $RE->{ flaky_first_fail } # `flaky' says it fails, will try again...
++ $RE->{ core_backtrace } # `core' shows the backtrace from the first fail
++ $RE->{ flaky_second_pass } # `flaky' says it passed on second try
++ \z
++ |xms;
++
++ # merged stdout/stderr from the above
++ Readonly my $LOG_VANISHING_CRASH_WITH_FLAKY_AND_CORE => qr|
++ \A
++ \QFirst attempt; crashing...\E \n
++ $RE->{ exited_with_signal11 }
++ $RE->{ flaky_first_fail }
++ $RE->{ core_backtrace }
++ \QSecond attempt; causing much vexation by passing!\E \n
++ $RE->{ flaky_second_pass }
++ \z
++ |xms;
++
++ # error from the above (when using "core" and "flaky" plugins, in that order)
++ # Note the only difference from above is that some output order is switched
++ Readonly my $ERROR_VANISHING_CRASH_WITH_CORE_AND_FLAKY => qr|
++ \A
++ $RE->{ exited_with_signal11 } # testrunner tells us that the test exited with signal 11
++ $RE->{ core_backtrace } # `core' shows the backtrace from the first fail
++ $RE->{ flaky_first_fail } # `flaky' says it fails, will try again...
++ $RE->{ flaky_second_pass } # `flaky' says it passed on second try
++ \z
++ |xms;
++
++ # merged stdout/stderr from the above
++ Readonly my $LOG_VANISHING_CRASH_WITH_CORE_AND_FLAKY => qr|
++ \A
++ \QFirst attempt; crashing...\E \n
++ $RE->{ exited_with_signal11 }
++ $RE->{ core_backtrace }
++ $RE->{ flaky_first_fail }
++ \QSecond attempt; causing much vexation by passing!\E \n
++ $RE->{ flaky_second_pass }
++ \z
++ |xms;
++
++ # perl to simulate a test which fails, then fails again in a different way
++ Readonly my $PERL_DIFFERING_FAILURE => <<'END_SCRIPT';
++ $|++;
++ if ($ENV{ QTQA_APP_TESTRUNNER_ATTEMPT } == 1) {
++ print qq{First attempt; failing...\n};
++ exit 13;
++ }
++ print qq{Second attempt; failing again, differently\n};
++ exit 22;
++ END_SCRIPT
++
++ # stdout from the above
++ Readonly my $OUTPUT_DIFFERING_FAILURE => <<'END_MESSAGE';
++ First attempt; failing...
++ Second attempt; failing again, differently
++ END_MESSAGE
++
++ # error from the above
++ Readonly my $ERROR_DIFFERING_FAILURE => <<'END_MESSAGE';
++ QtQA::App::TestRunner: test failed, running again to see if it is flaky...
++ QtQA::App::TestRunner: test failed on first and second attempts, but with different behavior each time:
++ QtQA::App::TestRunner: first attempt: exited with exit code 13
++ QtQA::App::TestRunner: second attempt: exited with exit code 22
++ QtQA::App::TestRunner: the test seems to be flaky, please fix this
++ END_MESSAGE
++
++ # above, in `pass' flaky mode
++ Readonly my $ERROR_DIFFERING_FAILURE_MODE_BEST => $ERROR_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a FAIL
++ END_MESSAGE
++
++ # above, in `fail' flaky mode
++ Readonly my $ERROR_DIFFERING_FAILURE_MODE_WORST => $ERROR_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a FAIL
++ END_MESSAGE
++
++ # above, with --verbose
++ Readonly my $VERBOSE_ERROR_DIFFERING_FAILURE_MODE_WORST => qr|
++ \A
++ $RE->{ verbose_begin }\n
++ \Q$ERROR_DIFFERING_FAILURE_MODE_WORST\E
++ $RE->{ verbose_end }\Q, exit code 22\E\n
++ |xms;
++
++ # above, in `ignore' flaky mode
++ Readonly my $ERROR_DIFFERING_FAILURE_MODE_IGNORE => $ERROR_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being ignored
++ END_MESSAGE
++
++ # stdout & stderr mixed from the above
++ Readonly my $LOG_DIFFERING_FAILURE => <<'END_MESSAGE';
++ First attempt; failing...
++ QtQA::App::TestRunner: test failed, running again to see if it is flaky...
++ Second attempt; failing again, differently
++ QtQA::App::TestRunner: test failed on first and second attempts, but with different behavior each time:
++ QtQA::App::TestRunner: first attempt: exited with exit code 13
++ QtQA::App::TestRunner: second attempt: exited with exit code 22
++ QtQA::App::TestRunner: the test seems to be flaky, please fix this
++ END_MESSAGE
++
++ # above, in `pass' flaky mode
++ Readonly my $LOG_DIFFERING_FAILURE_MODE_BEST => $LOG_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a FAIL
++ END_MESSAGE
++
++ # above, in `fail' flaky mode
++ Readonly my $LOG_DIFFERING_FAILURE_MODE_WORST => $LOG_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being treated as a FAIL
++ END_MESSAGE
++
++ # above, in `ignore' flaky mode
++ Readonly my $LOG_DIFFERING_FAILURE_MODE_IGNORE => $LOG_DIFFERING_FAILURE . <<"END_MESSAGE";
++ QtQA::App::TestRunner: this flaky test is being ignored
++ END_MESSAGE
++
++ # perl to check if -silent argument is passed (and fail)
++ Readonly my $PERL_SILENT_CHECK => <<'END_SCRIPT';
++ if (grep { $_ eq '-silent' } @ARGV) {
++ print qq{-silent argument is given; }.scalar(@ARGV).qq{ args\n};
++ } else {
++ print qq{-silent argument is not given; }.scalar(@ARGV).qq{ args\n};
++ }
++ exit 16;
++ END_SCRIPT
++
++ # expected output from the above, when run with -silent -foo
++ Readonly my $OUTPUT_SILENT_CHECK => <<'END_MESSAGE';
++ -silent argument is given; 2 args
++ -silent argument is not given; 1 args
++ END_MESSAGE
++
++ # expected stderr from the above
++ Readonly my $ERROR_SILENT_CHECK => <<'END_MESSAGE';
++ QtQA::App::TestRunner: test failed, running again to see if it is flaky...
++ QtQA::App::TestRunner: test failure could be reproduced twice consecutively
++ END_MESSAGE
++
++ sub test_run
++ {
++ my ($params_ref) = @_;
++
++ my @args = @{$params_ref->{ args }};
++ my $expected_stdout = $params_ref->{ expected_stdout };
++ my $expected_stderr = $params_ref->{ expected_stderr };
++ my $expected_success = $params_ref->{ expected_success };
++ my $expected_logfile = $params_ref->{ expected_logfile };
++ my $expected_logtext = $params_ref->{ expected_logtext } // "";
++ my $testname = $params_ref->{ testname } // q{};
++
++ my $status;
++ my ($output, $error) = capture {
++ $status = system( 'perl', "$FindBin::Bin/../testrunner.pl", @args );
++ };
++
++ if ($expected_success) {
++ is ( $status, 0, "$testname exits zero" );
++ }
++ else {
++ isnt( $status, 0, "$testname exits non-zero" );
++ }
++
++ is_or_like( $output, $expected_stdout, "$testname output looks correct" );
++ is_or_like( $error, $expected_stderr, "$testname error looks correct" );
++
++ # The rest of the verification steps are only applicable if a log file is expected and created
++ return if (!$expected_logfile);
++ return if (!ok( -e $expected_logfile, "$testname created $expected_logfile" ));
++
++ my $logtext = read_file( $expected_logfile ); # dies on error
++ is_or_like( $logtext, $expected_logtext, "$testname logtext is as expected" );
++
++ return;
++ }
++
++ sub test_testrunner_flaky
++ {
++ # control; check that `--plugin flaky' has no effect if a test doesn't fail
++ # flaky-mode should have no effect
++ foreach my $mode_args (
++ [],
++ ['--flaky-mode', 'worst'],
++ ['--flaky-mode', 'best'],
++ ['--flaky-mode', 'ignore'],
++ ) {
++ test_run({
++ testname => "plugin loads OK 0 exitcode (@{ $mode_args })",
++ args => [ qw(--plugin flaky), @{ $mode_args }, qw(-- perl -e),
++ 'print STDOUT q{Hi}; print STDERR q{there!}' ],
++ expected_success => 1,
++ expected_stdout => q{Hi},
++ expected_stderr => q{there!},
++ });
++ }
++
++ # stable failure
++ # flaky-mode should have no effect
++ foreach my $mode_args (
++ [],
++ ['--flaky-mode', 'worst'],
++ ['--flaky-mode', 'best'],
++ ['--flaky-mode', 'ignore'],
++ ) {
++ test_run({
++ testname => "stable failure (@{ $mode_args })",
++ args => [ qw(--plugin flaky), @{ $mode_args }, qw(-- perl -e),
++ 'print qq{Failing...\n}; exit 42' ],
++ expected_success => 0,
++ expected_stdout => qq{Failing...\n} x 2, # x 2 since retried once
++ expected_stderr => $ERROR_STABLE_FAILURE,
++ });
++ }
++
++ # test which fails once, then passes
++ test_run({
++ testname => 'vanishing failure',
++ args => [ qw(--plugin flaky -- perl -e), $PERL_VANISHING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_VANISHING_FAILURE,
++ expected_stderr => $ERROR_VANISHING_FAILURE_MODE_WORST,
++ });
++ test_run({
++ testname => 'vanishing failure (flaky-mode worst)',
++ args => [ qw(--plugin flaky --flaky-mode worst -- perl -e), $PERL_VANISHING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_VANISHING_FAILURE,
++ expected_stderr => $ERROR_VANISHING_FAILURE_MODE_WORST,
++ });
++ test_run({
++ testname => 'vanishing failure (flaky-mode best)',
++ args => [ qw(--plugin flaky --flaky-mode best -- perl -e), $PERL_VANISHING_FAILURE ],
++ expected_success => 1,
++ expected_stdout => $OUTPUT_VANISHING_FAILURE,
++ expected_stderr => $ERROR_VANISHING_FAILURE_MODE_BEST,
++ });
++ test_run({
++ testname => 'vanishing failure (flaky-mode ignore)',
++ args => [ qw(--plugin flaky --flaky-mode ignore -- perl -e), $PERL_VANISHING_FAILURE ],
++ expected_success => 1,
++ expected_stdout => $OUTPUT_VANISHING_FAILURE,
++ expected_stderr => $ERROR_VANISHING_FAILURE_MODE_IGNORE,
++ });
++
++
++ # test which eventually fails once, then eventually passes
++ # this also tests timeout warning by setting a smalltimeout value
++ test_run({
++ testname => 'vanishing failure; with timeoutwarning test',
++ args => [ qw(--plugin flaky --timeout 5 -- perl -e), $PERL_VANISHING_FAILURE_TIMEOUT_WARNING ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_VANISHING_FAILURE,
++ expected_stderr => $ERROR_VANISHING_FAILURE_MODE_WORST,
++ });
++
++ # test which fails once, then again in a different way
++ test_run({
++ testname => 'differing failure',
++ args => [ qw(--plugin flaky -- perl -e), $PERL_DIFFERING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_DIFFERING_FAILURE,
++ expected_stderr => $ERROR_DIFFERING_FAILURE_MODE_WORST,
++ });
++ test_run({
++ testname => 'differing failure (flaky-mode worst)',
++ args => [ qw(--verbose --plugin flaky --flaky-mode worst -- perl -e), $PERL_DIFFERING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_DIFFERING_FAILURE,
++ expected_stderr => $VERBOSE_ERROR_DIFFERING_FAILURE_MODE_WORST,
++ });
++ test_run({
++ testname => 'differing failure (flaky-mode best)',
++ args => [ qw(--plugin flaky --flaky-mode best -- perl -e), $PERL_DIFFERING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_DIFFERING_FAILURE,
++ expected_stderr => $ERROR_DIFFERING_FAILURE_MODE_BEST,
++ });
++ test_run({
++ testname => 'differing failure (flaky-mode ignore)',
++ args => [ qw(--plugin flaky --flaky-mode ignore -- perl -e), $PERL_DIFFERING_FAILURE ],
++ expected_success => 1,
++ expected_stdout => $OUTPUT_DIFFERING_FAILURE,
++ expected_stderr => $ERROR_DIFFERING_FAILURE_MODE_IGNORE,
++ });
++
++ # test -silent argument is omitted on second run
++ test_run({
++ testname => 'silent removed',
++ args => [ qw(--plugin flaky -- perl -e), $PERL_SILENT_CHECK, '--', '-silent', '-foo' ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_SILENT_CHECK,
++ expected_stderr => $ERROR_SILENT_CHECK,
++ });
++
++ # test which hangs should be retried as usual
++ test_run({
++ testname => "hanging failure",
++ args => [ qw(--timeout 2 --plugin flaky -- perl -e), $PERL_HANGING_FAILURE ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_HANGING_FAILURE,
++ expected_stderr => $ERROR_HANGING_FAILURE,
++ });
++
++ my $tempdir = tempdir( basename($0).'.XXXXXX', TMPDIR => 1, CLEANUP => 1 );
++
++ # basic check of interaction with logging
++ test_run({
++ testname => 'flaky with log',
++ args => [
++ '--capture-logs',
++ $tempdir,
++ '--plugin',
++ 'flaky',
++ '--',
++ 'perl',
++ '-e',
++ $PERL_DIFFERING_FAILURE,
++ ],
++ expected_success => 0,
++ expected_stdout => q{},
++ expected_stderr => q{},
++ expected_logfile => "$tempdir/perl-00.txt",
++ expected_logtext => $LOG_DIFFERING_FAILURE_MODE_WORST,
++ });
++
++ # interaction with core
++ # (core only works on linux)
++ if ($OSNAME =~ m{linux}i) {
++ test_run({
++ testname => 'flaky with tee log and core (flaky, core)',
++ args => [
++ '--tee-logs',
++ $tempdir,
++ '--plugin',
++ 'flaky',
++ '--flaky-mode', # note we are testing mixing of plugin args
++ 'worst', # with global testrunner args.
++ '--plugin',
++ 'core',
++ '--',
++ 'perl',
++ '-e',
++ $PERL_VANISHING_CRASH,
++ ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_VANISHING_CRASH,
++ expected_stderr => $ERROR_VANISHING_CRASH_WITH_FLAKY_AND_CORE,
++ expected_logfile => "$tempdir/perl-01.txt",
++ expected_logtext => $LOG_VANISHING_CRASH_WITH_FLAKY_AND_CORE,
++ });
++
++ # switch the order and verify that this affects the plugin order
++ test_run({
++ testname => 'flaky with tee log and core (core, flaky)',
++ args => [
++ '--tee-logs',
++ $tempdir,
++ '--plugin',
++ 'core',
++ '--plugin',
++ 'flaky',
++ '--',
++ 'perl',
++ '-e',
++ $PERL_VANISHING_CRASH,
++ ],
++ expected_success => 0,
++ expected_stdout => $OUTPUT_VANISHING_CRASH,
++ expected_stderr => $ERROR_VANISHING_CRASH_WITH_CORE_AND_FLAKY,
++ expected_logfile => "$tempdir/perl-02.txt",
++ expected_logtext => $LOG_VANISHING_CRASH_WITH_CORE_AND_FLAKY,
++ });
++ }
++
++ return;
++ }
++
++ sub run
++ {
++ test_testrunner_flaky;
++ done_testing;
++
++ return;
++ }
++
++ run if (!caller);
++ 1;
++