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