From f9215b6519d4732498e598de9a3581297c60c4e8 Mon Sep 17 00:00:00 2001
From: Nikita Popov <nikita.ppv@gmail.com>
Date: Fri, 21 Apr 2017 12:29:41 +0200
Subject: [PATCH] Support showing slow tests in run-tests.php

---
 .travis.yml            |  2 +-
 appveyor/test_task.bat |  2 +-
 run-tests.php          | 37 ++++++++++++++++++++++++++++++++++++-
 3 files changed, 38 insertions(+), 3 deletions(-)

diff --git a/.travis.yml b/.travis.yml
index f0f82cc660..c5db1fdd1b 100644
--- 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 9f9e238ed3..2ba69e9610 100644
--- 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 c1c5b99921..3bfbf76ce0 100755
--- 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 .= '
 =====================================================================
-- 
2.50.1