Support showing slow tests in run-tests.php

diff --git a/.travis.yml b/.travis.yml
index f0f82cc660af6029145d82b09700bf33ee40fa9f..c5db1fdd1b9f6d62427d822b2c851a8bde5c1d4b 100644 (file)
--- a/.travis.yml
+++ b/.travis.yml
@@ -60,7 +60,7 @@ before_script:
 
 # Run PHPs run-tests.php 
 script:
-    - ./sapi/cli/php run-tests.php -p `pwd`/sapi/cli/php $(if [ $ENABLE_DEBUG == 1 ]; then echo "-d opcache.enable_cli=1 -d zend_extension=`pwd`/modules/opcache.so"; fi) -g "FAIL,XFAIL,BORK,WARN,LEAK,SKIP" --offline --show-diff --set-timeout 120
+    - ./sapi/cli/php run-tests.php -p `pwd`/sapi/cli/php $(if [ $ENABLE_DEBUG == 1 ]; then echo "-d opcache.enable_cli=1 -d zend_extension=`pwd`/modules/opcache.so"; fi) -g "FAIL,XFAIL,BORK,WARN,LEAK,SKIP" --offline --show-diff --show-slow 1000 --set-timeout 120
 
 after_success:
     - ccache --show-stats

diff --git a/appveyor/test_task.bat b/appveyor/test_task.bat
index 9f9e238ed330f9ed6a644a564ec071d151b927c8..2ba69e9610b3efcafc972a86b5410c96d73a0d63 100644 (file)
--- a/appveyor/test_task.bat
+++ b/appveyor/test_task.bat
@@ -71,5 +71,5 @@ copy %PHP_BUILD_CACHE_ENCHANT_DICT_DIR%\* %USERPROFILE%\enchant\myspell
 mkdir c:\tests_tmp
 
 cd "%APPVEYOR_BUILD_FOLDER%"
-nmake test TESTS="%OPCACHE_OPTS% -q --offline --show-diff --set-timeout 120 -g FAIL,XFAIL,BORK,WARN,LEAK,SKIP --temp-source c:\tests_tmp --temp-target c:\tests_tmp"
+nmake test TESTS="%OPCACHE_OPTS% -q --offline --show-diff --show-slow 1000 --set-timeout 120 -g FAIL,XFAIL,BORK,WARN,LEAK,SKIP --temp-source c:\tests_tmp --temp-target c:\tests_tmp"
 

diff --git a/run-tests.php b/run-tests.php
index c1c5b9992196374f46bfc8e09d980453c8bd3be0..3bfbf76ce0159f39679d52304be832e92f67d67a 100755 (executable)
--- a/run-tests.php
+++ b/run-tests.php
@@ -456,7 +456,7 @@ function save_or_mail_results()
 $test_files = array();
 $redir_tests = array();
 $test_results = array();
-$PHP_FAILED_TESTS = array('BORKED' => array(), 'FAILED' => array(), 'WARNED' => array(), 'LEAKED' => array(), 'XFAILED' => array());
+$PHP_FAILED_TESTS = array('BORKED' => array(), 'FAILED' => array(), 'WARNED' => array(), 'LEAKED' => array(), 'XFAILED' => array(), 'SLOW' => array());
 
 // If parameters given assume they represent selected tests to run.
 $failed_tests_file= false;
@@ -474,6 +474,7 @@ $temp_target = null;
 $temp_urlbase = null;
 $conf_passed = null;
 $no_clean = false;
+$slow_min_ms = INF;
 
 $cfgtypes = array('show', 'keep');
 $cfgfiles = array('skip', 'php', 'clean', 'out', 'diff', 'exp');
@@ -631,6 +632,9 @@ if (isset($argc) && $argc > 1) {
                                                $cfg['show'][$file] = true;
                                        }
                                        break;
+                               case '--show-slow':
+                                       $slow_min_ms = $argv[++$i];
+                                       break;
                                case '--temp-source':
                                        $temp_source = $argv[++$i];
                                        break;
@@ -746,6 +750,9 @@ Options:
                 get written independent of the log format, however 'diff' only
                 exists when a test fails.
 
+    --show-slow [n]
+                Show all tests that took longer than [n] milliseconds to run.
+
     --no-clean  Do not execute clean section if any.
 
 HELP;
@@ -1211,6 +1218,7 @@ function run_test($php, $file, $env)
        global $valgrind_version;
        global $SHOW_ONLY_GROUPS;
        global $no_file_cache;
+       global $slow_min_ms;
        $temp_filenames = null;
        $org_file = $file;
 
@@ -1895,10 +1903,21 @@ COMMAND $cmd
 ";
 
        junit_start_timer($shortname);
+       $startTime = microtime(true);
 
        $out = system_with_timeout($cmd, $env, isset($section_text['STDIN']) ? $section_text['STDIN'] : null, $captureStdIn, $captureStdOut, $captureStdErr);
 
        junit_finish_timer($shortname);
+       $time = microtime(true) - $startTime;
+       if ($time * 1000 >= $slow_min_ms) {
+               $PHP_FAILED_TESTS['SLOW'][] = array(
+                       'name'      => $file,
+                       'test_name' => (is_array($IN_REDIRECT) ? $IN_REDIRECT['via'] : '') . $tested . " [$tested_file]",
+                       'output'    => '',
+                       'diff'      => '',
+                       'info'      => $time,
+               );
+       }
 
        if (array_key_exists('CLEAN', $section_text) && (!$no_clean || $cfg['keep']['clean'])) {
 
@@ -2480,6 +2499,22 @@ Time taken      : ' . sprintf('%4d seconds', $end_time - $start_time) . '
 ';
        $failed_test_summary = '';
 
+       if (count($PHP_FAILED_TESTS['SLOW'])) {
+               usort($PHP_FAILED_TESTS['SLOW'], function($a, $b) {
+                       return $a['info'] < $b['info'] ? 1 : -1;
+               });
+
+               $failed_test_summary .= '
+=====================================================================
+SLOW TEST SUMMARY
+---------------------------------------------------------------------
+';
+               foreach ($PHP_FAILED_TESTS['SLOW'] as $failed_test_data) {
+                       $failed_test_summary .= sprintf('(%.3f s) ', $failed_test_data['info']) . $failed_test_data['test_name'] . "\n";
+               }
+               $failed_test_summary .=  "=====================================================================\n";
+       }
+
        if (count($PHP_FAILED_TESTS['XFAILED'])) {
                $failed_test_summary .= '
 =====================================================================