diff --git a/.github/workflows/reusable-phpunit-tests-v3.yml b/.github/workflows/reusable-phpunit-tests-v3.yml index 8a225134a2c38..6485f2aa3f9d8 100644 --- a/.github/workflows/reusable-phpunit-tests-v3.yml +++ b/.github/workflows/reusable-phpunit-tests-v3.yml @@ -126,6 +126,7 @@ jobs: # - Logs debug information about what's installed within the WordPress Docker containers. # - Install WordPress within the Docker container. # - Run the PHPUnit tests. + # - Flags slow PHPUnit tests with GitHub Actions annotations and a run summary. # - Publish PHPUnit timing metrics to CodeVitals. # - Upload the code coverage report to Codecov.io. # - Ensures version-controlled files are not modified or deleted. @@ -273,6 +274,28 @@ jobs: TEST_GROUPS: ${{ inputs.phpunit-test-groups }} MULTISITE_FLAG: ${{ inputs.multisite && 'multisite' || 'single' }} + - name: Flag slow PHPUnit tests + # Runs when the test step succeeds or fails, but skips cancelled jobs. + # This step never fails the job itself (continue-on-error), because the + # slow-test signal is advisory only. + if: >- + ${{ + ! cancelled() && inputs.report && inputs.php == '8.5' && + ( github.event_name == 'pull_request' || + ( github.event_name == 'push' && github.ref == 'refs/heads/trunk' ) ) + }} + continue-on-error: true + run: | + if [ -f tests/phpunit/build/logs/junit.xml ]; then + php tests/phpunit/prepare-slow-test-annotations.php \ + tests/phpunit/build/logs/junit.xml \ + 1.0 \ + 20 \ + "$RUNNER_TEMP/phpunit-timing-metrics.json" + else + echo 'PHPUnit JUnit report not found; skipping slow-test annotations.' + fi + - name: Publish PHPUnit timing metrics continue-on-error: true if: | @@ -295,6 +318,7 @@ jobs: trunk \ "$GITHUB_SHA" \ "$COMMITTED_AT" \ + "$RUNNER_TEMP/phpunit-timing-metrics.json" \ | curl --fail-with-body --silent --show-error \ --request POST \ --header 'Content-Type: application/json' \ diff --git a/tests/phpunit/includes/class-wp-phpunit-timing-metrics.php b/tests/phpunit/includes/class-wp-phpunit-timing-metrics.php index 1276154a32854..3d7b6e61d693f 100644 --- a/tests/phpunit/includes/class-wp-phpunit-timing-metrics.php +++ b/tests/phpunit/includes/class-wp-phpunit-timing-metrics.php @@ -8,50 +8,93 @@ final class WP_PHPUnit_Timing_Metrics { /** * Extracts timing metrics from a JUnit XML file. * - * @param string $file Path to the JUnit XML file. + * @param string $file Path to the JUnit XML file. + * @param callable|null $testcase_callback Optional callback invoked for each timed testcase. * @return array Timing metrics keyed for CodeVitals. - * @throws RuntimeException If the file cannot be read or contains invalid timing data. + * @throws RuntimeException If the file cannot be read or contains invalid XML. */ - public static function from_file( $file ) { + public static function from_file( $file, $testcase_callback = null ) { if ( ! is_readable( $file ) ) { throw new RuntimeException( 'The JUnit timing report could not be read.' ); } - $reader = new XMLReader(); - if ( ! $reader->open( $file, null, LIBXML_NONET | LIBXML_COMPACT ) ) { - throw new RuntimeException( 'The JUnit timing report could not be opened.' ); + if ( null !== $testcase_callback && ! is_callable( $testcase_callback ) ) { + throw new InvalidArgumentException( 'The testcase callback must be callable.' ); } - $suite_time = null; - $test_times = array(); + $reader = new XMLReader(); + $previous_libxml_state = libxml_use_internal_errors( true ); + $reader_is_open = false; + $suite_time = null; + $test_times = array(); + $xml_errors = array(); - while ( $reader->read() ) { - if ( XMLReader::ELEMENT !== $reader->nodeType ) { - continue; + libxml_clear_errors(); + + try { + if ( ! $reader->open( $file, null, LIBXML_NONET | LIBXML_COMPACT ) ) { + throw new RuntimeException( 'The JUnit timing report could not be opened.' ); } - if ( null === $suite_time && 'testsuite' === $reader->name ) { + $reader_is_open = true; + + while ( $reader->read() ) { + if ( XMLReader::ELEMENT !== $reader->nodeType ) { + continue; + } + + if ( null === $suite_time && 'testsuite' === $reader->name ) { + $time = $reader->getAttribute( 'time' ); + if ( is_numeric( $time ) ) { + $suite_time = (float) $time; + } + continue; + } + + if ( 'testcase' !== $reader->name ) { + continue; + } + $time = $reader->getAttribute( 'time' ); - if ( is_numeric( $time ) ) { - $suite_time = (float) $time; + + // A testcase without numeric timing, such as a skipped test, carries + // no timing signal and is excluded from the aggregate metrics. + if ( ! is_numeric( $time ) ) { + continue; } - continue; - } - if ( 'testcase' !== $reader->name ) { - continue; + $test_time = (float) $time; + $test_times[] = $test_time; + + if ( null !== $testcase_callback ) { + $testcase_callback( + array( + 'name' => (string) $reader->getAttribute( 'name' ), + 'class' => (string) $reader->getAttribute( 'class' ), + 'file' => (string) $reader->getAttribute( 'file' ), + 'line' => (string) $reader->getAttribute( 'line' ), + 'time' => $test_time, + 'time_display' => (string) $time, + ) + ); + } } - $time = $reader->getAttribute( 'time' ); - if ( ! is_numeric( $time ) ) { + $xml_errors = libxml_get_errors(); + } finally { + if ( $reader_is_open ) { $reader->close(); - throw new RuntimeException( 'A JUnit testcase is missing numeric timing data.' ); } - $test_times[] = (float) $time; + libxml_clear_errors(); + libxml_use_internal_errors( $previous_libxml_state ); } - $reader->close(); + foreach ( $xml_errors as $xml_error ) { + if ( LIBXML_ERR_WARNING < $xml_error->level ) { + throw new RuntimeException( 'The JUnit timing report contains invalid XML.' ); + } + } if ( ! $test_times ) { throw new RuntimeException( 'The JUnit timing report contains no testcases.' ); diff --git a/tests/phpunit/prepare-slow-test-annotations.php b/tests/phpunit/prepare-slow-test-annotations.php new file mode 100644 index 0000000000000..27ae6af2cd6bf --- /dev/null +++ b/tests/phpunit/prepare-slow-test-annotations.php @@ -0,0 +1,241 @@ +#!/usr/bin/env php + \ + * [threshold-seconds] [max-summary-tests] [timing-metrics-file] + * + * @package WordPress + * @subpackage UnitTests + */ + +require_once __DIR__ . '/includes/class-wp-phpunit-timing-metrics.php'; + +/** + * Escapes a GitHub Actions workflow command message. + * + * @param string $value Message to escape. + * @return string Escaped message. + */ +function wp_phpunit_escape_command_message( $value ) { + return str_replace( + array( '%', "\r", "\n" ), + array( '%25', '%0D', '%0A' ), + $value + ); +} + +/** + * Escapes a GitHub Actions workflow command property. + * + * @param string $value Property value to escape. + * @return string Escaped property value. + */ +function wp_phpunit_escape_command_property( $value ) { + return str_replace( + array( ',', ':' ), + array( '%2C', '%3A' ), + wp_phpunit_escape_command_message( $value ) + ); +} + +/** + * Escapes text for a Markdown table cell. + * + * @param string $value Cell value to escape. + * @return string Escaped cell value. + */ +function wp_phpunit_escape_markdown_cell( $value ) { + return str_replace( + array( '|', "\r", "\n" ), + array( '\\|', ' ', ' ' ), + $value + ); +} + +/** + * Converts a container-absolute test path to a repository-relative one. + * + * PHPUnit records absolute paths (the repository is mounted at /var/www in the + * Docker environment). GitHub annotations need repository-relative paths to + * resolve to a line, so a known workspace prefix is stripped when present. + * + * @param string $file Path recorded in the JUnit report. + * @return string Repository-relative path, or the input unchanged. + */ +function wp_phpunit_relative_path( $file ) { + if ( '' === $file ) { + return ''; + } + + $prefixes = array( '/var/www/' ); + $workspace = getenv( 'GITHUB_WORKSPACE' ); + + if ( is_string( $workspace ) && '' !== $workspace ) { + $prefixes[] = rtrim( $workspace, '/' ) . '/'; + } + + foreach ( $prefixes as $prefix ) { + if ( 0 === strncmp( $file, $prefix, strlen( $prefix ) ) ) { + return substr( $file, strlen( $prefix ) ); + } + } + + return $file; +} + +/** + * Appends a summary to GitHub Actions or writes it to standard output. + * + * @param string $summary Markdown summary. + * @return void + * @throws RuntimeException If the GitHub Actions summary cannot be written. + */ +function wp_phpunit_write_summary( $summary ) { + $summary_file = getenv( 'GITHUB_STEP_SUMMARY' ); + + if ( false === $summary_file || '' === $summary_file ) { + echo $summary; + return; + } + + if ( false === file_put_contents( $summary_file, $summary, FILE_APPEND ) ) { + throw new RuntimeException( 'The GitHub Actions step summary could not be written.' ); + } +} + +if ( $argc < 2 || $argc > 5 ) { + fwrite( + STDERR, + 'Usage: php tests/phpunit/prepare-slow-test-annotations.php ' + . "[threshold-seconds] [max-summary-tests] [timing-metrics-file]\n" + ); + exit( 1 ); +} + +try { + $file = $argv[1]; + $threshold_value = $argv[2] ?? '1.0'; + $max_summary_tests_value = $argv[3] ?? '20'; + $timing_metrics_file = $argv[4] ?? null; + + if ( ! is_numeric( $threshold_value ) || (float) $threshold_value < 0 ) { + throw new RuntimeException( 'The slow-test threshold must be a non-negative number.' ); + } + + if ( ! ctype_digit( $max_summary_tests_value ) || (int) $max_summary_tests_value < 1 ) { + throw new RuntimeException( 'The maximum summary test count must be a positive integer.' ); + } + + $threshold = (float) $threshold_value; + $max_summary_tests = (int) $max_summary_tests_value; + $slow_tests = array(); + $timing_metrics = WP_PHPUnit_Timing_Metrics::from_file( + $file, + static function ( $testcase ) use ( &$slow_tests, $threshold ) { + if ( $testcase['time'] <= $threshold ) { + return; + } + + $testcase['file'] = wp_phpunit_relative_path( $testcase['file'] ); + $slow_tests[] = $testcase; + } + ); + + if ( null !== $timing_metrics_file ) { + $timing_metrics_json = json_encode( $timing_metrics, JSON_THROW_ON_ERROR ); + + if ( false === file_put_contents( $timing_metrics_file, $timing_metrics_json . "\n" ) ) { + throw new RuntimeException( 'The PHPUnit timing metrics file could not be written.' ); + } + } + + usort( + $slow_tests, + static function ( $left, $right ) { + if ( $left['time'] === $right['time'] ) { + return strcmp( $left['class'] . '::' . $left['name'], $right['class'] . '::' . $right['name'] ); + } + + return $right['time'] <=> $left['time']; + } + ); + + if ( ! $slow_tests ) { + wp_phpunit_write_summary( "No PHPUnit tests exceeded {$threshold_value}s.\n" ); + exit( 0 ); + } + + $total_slow_tests = count( $slow_tests ); + $summary_tests = array_slice( $slow_tests, 0, $max_summary_tests ); + + // GitHub Actions renders at most 10 warning annotations per step, so the inline + // annotations are capped there while the summary table below can list more. + foreach ( array_slice( $slow_tests, 0, 10 ) as $test ) { + $properties = array(); + + if ( '' !== $test['file'] ) { + $properties[] = 'file=' . wp_phpunit_escape_command_property( $test['file'] ); + + if ( '' !== $test['line'] ) { + $properties[] = 'line=' . wp_phpunit_escape_command_property( $test['line'] ); + } + } + + $properties[] = 'title=' . wp_phpunit_escape_command_property( 'Slow PHPUnit test' ); + $message = sprintf( + '%s::%s took %ss', + $test['class'], + $test['name'], + $test['time_display'] + ); + + printf( + "::warning %s::%s\n", + implode( ',', $properties ), + wp_phpunit_escape_command_message( $message ) + ); + } + + $summary = "### Slowest PHPUnit tests (main suite, over {$threshold_value}s)\n\n"; + + if ( $total_slow_tests > count( $summary_tests ) ) { + $summary .= sprintf( + "Showing the %d slowest of %d tests above the threshold.\n\n", + count( $summary_tests ), + $total_slow_tests + ); + } + + $summary .= "| Test | Time (s) | File:line |\n"; + $summary .= "| --- | ---: | --- |\n"; + + foreach ( $summary_tests as $test ) { + $location = $test['file']; + + if ( '' !== $test['line'] ) { + $location .= ( '' !== $location ? ':' : 'Line ' ) . $test['line']; + } + + if ( '' === $location ) { + $location = '—'; + } + + $summary .= sprintf( + "| %s::%s | %s | %s |\n", + wp_phpunit_escape_markdown_cell( $test['class'] ), + wp_phpunit_escape_markdown_cell( $test['name'] ), + $test['time_display'], + wp_phpunit_escape_markdown_cell( $location ) + ); + } + + wp_phpunit_write_summary( $summary ); +} catch ( Throwable $error ) { + fwrite( STDERR, $error->getMessage() . "\n" ); + exit( 1 ); +} diff --git a/tests/phpunit/prepare-timing-results.php b/tests/phpunit/prepare-timing-results.php index 46a97b3596f39..7cef109048237 100644 --- a/tests/phpunit/prepare-timing-results.php +++ b/tests/phpunit/prepare-timing-results.php @@ -10,12 +10,44 @@ require_once __DIR__ . '/includes/class-wp-phpunit-timing-metrics.php'; -if ( 5 !== $argc ) { - fwrite( STDERR, "Usage: prepare-timing-results.php \n" ); +if ( 5 !== $argc && 6 !== $argc ) { + fwrite( STDERR, "Usage: prepare-timing-results.php [timing-metrics-file]\n" ); exit( 1 ); } try { + if ( 6 === $argc ) { + if ( ! is_readable( $argv[5] ) ) { + throw new RuntimeException( 'The prepared PHPUnit timing metrics could not be read.' ); + } + + $timing_metrics_json = file_get_contents( $argv[5] ); + + if ( false === $timing_metrics_json ) { + throw new RuntimeException( 'The prepared PHPUnit timing metrics could not be read.' ); + } + + $timing_metrics = json_decode( $timing_metrics_json, true, 512, JSON_THROW_ON_ERROR ); + $metric_keys = array( + 'phpunit-suite-time', + 'phpunit-p95-test-time', + 'phpunit-p99-test-time', + 'phpunit-max-test-time', + 'phpunit-tests-over-500ms', + 'phpunit-tests-over-1s', + ); + + if ( + ! is_array( $timing_metrics ) + || array_keys( $timing_metrics ) !== $metric_keys + || count( $timing_metrics ) !== count( array_filter( $timing_metrics, 'is_numeric' ) ) + ) { + throw new RuntimeException( 'The prepared PHPUnit timing metrics are invalid.' ); + } + } else { + $timing_metrics = WP_PHPUnit_Timing_Metrics::from_file( $argv[1] ); + } + $timestamp = new DateTimeImmutable( $argv[4] ); $payload = array( 'branch' => $argv[2], @@ -23,7 +55,7 @@ 'baseHash' => $argv[3], 'baseMetrics' => new stdClass(), 'timestamp' => $timestamp->format( DATE_ATOM ), - 'metrics' => WP_PHPUnit_Timing_Metrics::from_file( $argv[1] ), + 'metrics' => $timing_metrics, ); echo json_encode( $payload, JSON_THROW_ON_ERROR ) . "\n"; diff --git a/tests/phpunit/tests/includes/junitTimingMetrics.php b/tests/phpunit/tests/includes/junitTimingMetrics.php index 993f5d84da22b..c6465615c55ea 100644 --- a/tests/phpunit/tests/includes/junitTimingMetrics.php +++ b/tests/phpunit/tests/includes/junitTimingMetrics.php @@ -61,6 +61,55 @@ public function test_uses_testcase_time_when_suite_time_is_missing() { $this->assertSame( 0.6, $metrics['phpunit-suite-time'] ); } + public function test_passes_timed_testcase_details_to_callback() { + $file = $this->create_junit_file( array( 0.25, 1.5 ), 1.75 ); + $testcases = array(); + + WP_PHPUnit_Timing_Metrics::from_file( + $file, + static function ( $testcase ) use ( &$testcases ) { + $testcases[] = $testcase; + } + ); + + $this->assertSame( + array( + array( + 'name' => 'test_0', + 'class' => 'Tests_Example', + 'file' => '/var/www/tests/phpunit/tests/example.php', + 'line' => '100', + 'time' => 0.25, + 'time_display' => '0.25', + ), + array( + 'name' => 'test_1', + 'class' => 'Tests_Example', + 'file' => '/var/www/tests/phpunit/tests/example.php', + 'line' => '101', + 'time' => 1.5, + 'time_display' => '1.5', + ), + ), + $testcases + ); + } + + public function test_ignores_testcase_without_numeric_timing() { + $file = $this->create_junit_file( array( 0.5, null, 1.5 ), 2.0 ); + $testcases = array(); + + $metrics = WP_PHPUnit_Timing_Metrics::from_file( + $file, + static function ( $testcase ) use ( &$testcases ) { + $testcases[] = $testcase; + } + ); + + $this->assertCount( 2, $testcases ); + $this->assertSame( 1500.0, $metrics['phpunit-max-test-time'] ); + } + public function test_rejects_report_without_testcases() { $file = $this->create_junit_file( array(), 0.0 ); @@ -70,14 +119,48 @@ public function test_rejects_report_without_testcases() { WP_PHPUnit_Timing_Metrics::from_file( $file ); } + public function test_rejects_invalid_xml() { + $file = $this->create_temporary_file( '' ); + + $this->expectException( RuntimeException::class ); + $this->expectExceptionMessage( 'The JUnit timing report contains invalid XML.' ); + + WP_PHPUnit_Timing_Metrics::from_file( $file ); + } + /** * Creates a JUnit XML file for a test. * - * @param float[] $times Testcase times in seconds. - * @param float|int $suite_time Optional testsuite time in seconds. + * @param array $times Testcase times in seconds. Null omits the timing attribute. + * @param float|int|null $suite_time Optional testsuite time in seconds. * @return string Path to the temporary file. */ private function create_junit_file( $times, $suite_time = null ) { + $suite_time_attribute = null === $suite_time ? '' : sprintf( ' time="%s"', $suite_time ); + $testcases = ''; + + foreach ( $times as $index => $time ) { + $time_attribute = null === $time ? '' : sprintf( ' time="%s"', $time ); + $testcases .= sprintf( + '', + $index, + 100 + $index, + $time_attribute + ); + } + + return $this->create_temporary_file( + sprintf( '%3$s', count( $times ), $suite_time_attribute, $testcases ) + ); + } + + /** + * Creates a temporary file containing the provided data. + * + * @param string $data File contents. + * @return string Path to the temporary file. + */ + private function create_temporary_file( $data ) { $file = tempnam( sys_get_temp_dir(), 'junit-timing-' ); if ( false === $file ) { @@ -85,17 +168,7 @@ private function create_junit_file( $times, $suite_time = null ) { } $this->temporary_files[] = $file; - $suite_time_attribute = null === $suite_time ? '' : sprintf( ' time="%s"', $suite_time ); - $testcases = ''; - - foreach ( $times as $index => $time ) { - $testcases .= sprintf( '', $index, $time ); - } - - file_put_contents( - $file, - sprintf( '%3$s', count( $times ), $suite_time_attribute, $testcases ) - ); + file_put_contents( $file, $data ); return $file; }