New Performance report to measure sniff run time performance

package.xml

@@ -328,6 +328,7 @@ http://pear.php.net/dtd/package-2.0.xsd">
      <file baseinstalldir="PHP/CodeSniffer" name="Json.php" role="php" />
      <file baseinstalldir="PHP/CodeSniffer" name="Junit.php" role="php" />
      <file baseinstalldir="PHP/CodeSniffer" name="Notifysend.php" role="php" />
+     <file baseinstalldir="PHP/CodeSniffer" name="Performance.php" role="php" />
      <file baseinstalldir="PHP/CodeSniffer" name="Report.php" role="php" />
      <file baseinstalldir="PHP/CodeSniffer" name="Source.php" role="php" />
      <file baseinstalldir="PHP/CodeSniffer" name="Summary.php" role="php" />

src/Config.php

@@ -143,6 +143,7 @@ class Config
         'stdin'           => null,
         'stdinContent'    => null,
         'stdinPath'       => null,
+        'trackTime'       => null,
         'unknown'         => null,
     ];
 
@@ -264,6 +265,20 @@ public function __set($name, $value)
 
             $value = $cleaned;
             break;
+
+        // Only track time when explicitly needed.
+        case 'verbosity':
+            if ($value > 2) {
+                $this->settings['trackTime'] = true;
+            }
+            break;
+        case 'reports':
+            $reports = array_change_key_case($value, CASE_LOWER);
+            if (array_key_exists('performance', $reports) === true) {
+                $this->settings['trackTime'] = true;
+            }
+            break;
+
         default :
             // No validation required.
             break;
@@ -517,6 +532,7 @@ public function restoreDefaults()
         $this->stdin           = false;
         $this->stdinContent    = null;
         $this->stdinPath       = null;
+        $this->trackTime       = false;
         $this->unknown         = [];
 
         $standard = self::getConfigData('default_standard');
@@ -1411,8 +1427,8 @@ public function printPHPCSUsage()
         echo ' <processes>    How many files should be checked simultaneously (default is 1)'.PHP_EOL;
         echo ' <report>       Print either the "full", "xml", "checkstyle", "csv"'.PHP_EOL;
         echo '                "json", "junit", "emacs", "source", "summary", "diff"'.PHP_EOL;
-        echo '                "svnblame", "gitblame", "hgblame" or "notifysend" report,'.PHP_EOL;
-        echo '                or specify the path to a custom report class'.PHP_EOL;
+        echo '                "svnblame", "gitblame", "hgblame", "notifysend" or "performance",'.PHP_EOL;
+        echo '                report or specify the path to a custom report class'.PHP_EOL;
         echo '                (the "full" report is printed by default)'.PHP_EOL;
         echo ' <reportFile>   Write the report to the specified file path'.PHP_EOL;
         echo ' <reportWidth>  How many columns wide screen reports should be printed'.PHP_EOL;

src/Files/File.php

@@ -209,6 +209,7 @@ class File
      * An array of sniffs being processed and how long they took.
      *
      * @var array
+     * @see getListenerTimes()
      */
     protected $listenerTimes = [];
 
@@ -253,6 +254,7 @@ public function __construct($path, Ruleset $ruleset, Config $config)
         $this->configCache['errorSeverity']   = $this->config->errorSeverity;
         $this->configCache['warningSeverity'] = $this->config->warningSeverity;
         $this->configCache['recordErrors']    = $this->config->recordErrors;
+        $this->configCache['trackTime']       = $this->config->trackTime;
         $this->configCache['ignorePatterns']  = $this->ruleset->ignorePatterns;
         $this->configCache['includePatterns'] = $this->ruleset->includePatterns;
 
@@ -496,8 +498,11 @@ public function process()
 
                 $this->activeListener = $class;
 
-                if (PHP_CODESNIFFER_VERBOSITY > 2) {
+                if ($this->configCache['trackTime'] === true) {
                     $startTime = microtime(true);
+                }
+
+                if (PHP_CODESNIFFER_VERBOSITY > 2) {
                     echo "\t\t\tProcessing ".$this->activeListener.'... ';
                 }
 
@@ -506,14 +511,16 @@ public function process()
                     $listenerIgnoreTo[$this->activeListener] = $ignoreTo;
                 }
 
-                if (PHP_CODESNIFFER_VERBOSITY > 2) {
+                if ($this->configCache['trackTime'] === true) {
                     $timeTaken = (microtime(true) - $startTime);
                     if (isset($this->listenerTimes[$this->activeListener]) === false) {
                         $this->listenerTimes[$this->activeListener] = 0;
                     }
 
                     $this->listenerTimes[$this->activeListener] += $timeTaken;
+                }
 
+                if (PHP_CODESNIFFER_VERBOSITY > 2) {
                     $timeTaken = round(($timeTaken), 4);
                     echo "DONE in $timeTaken seconds".PHP_EOL;
                 }
@@ -540,8 +547,7 @@ public function process()
             echo "\t*** END TOKEN PROCESSING ***".PHP_EOL;
             echo "\t*** START SNIFF PROCESSING REPORT ***".PHP_EOL;
 
-            asort($this->listenerTimes, SORT_NUMERIC);
-            $this->listenerTimes = array_reverse($this->listenerTimes, true);
+            arsort($this->listenerTimes, SORT_NUMERIC);
             foreach ($this->listenerTimes as $listener => $timeTaken) {
                 echo "\t$listener: ".round(($timeTaken), 4).' secs'.PHP_EOL;
             }
@@ -1216,6 +1222,18 @@ public function getMetrics()
     }//end getMetrics()
 
 
+    /**
+     * Returns the time taken processing this file for each invoked sniff.
+     *
+     * @return array
+     */
+    public function getListenerTimes()
+    {
+        return $this->listenerTimes;
+
+    }//end getListenerTimes()
+
+
     /**
      * Returns the absolute filename of this file.
      *

src/Reports/Performance.php

@@ -0,0 +1,160 @@
+<?php
+/**
+ * Performance report for PHP_CodeSniffer.
+ *
+ * @author    Juliette Reinders Folmer <phpcs_nospam@adviesenzo.nl>
+ * @copyright 2023 Juliette Reinders Folmer. All rights reserved.
+ * @license   https://github.com/squizlabs/PHP_CodeSniffer/blob/master/licence.txt BSD Licence
+ */
+
+namespace PHP_CodeSniffer\Reports;
+
+use PHP_CodeSniffer\Files\File;
+use PHP_CodeSniffer\Util\Common;
+use PHP_CodeSniffer\Util\Timing;
+
+class Performance implements Report
+{
+
+
+    /**
+     * Generate a partial report for a single processed file.
+     *
+     * Function should return TRUE if it printed or stored data about the file
+     * and FALSE if it ignored the file. Returning TRUE indicates that the file and
+     * its data should be counted in the grand totals.
+     *
+     * @param array                 $report      Prepared report data.
+     * @param \PHP_CodeSniffer\File $phpcsFile   The file being reported on.
+     * @param bool                  $showSources Show sources?
+     * @param int                   $width       Maximum allowed line width.
+     *
+     * @return bool
+     */
+    public function generateFileReport($report, File $phpcsFile, $showSources=false, $width=80)
+    {
+        $times = $phpcsFile->getListenerTimes();
+        foreach ($times as $sniff => $time) {
+            echo "$sniff>>$time".PHP_EOL;
+        }
+
+        return true;
+
+    }//end generateFileReport()
+
+
+    /**
+     * Prints the sniff performance report.
+     *
+     * @param string $cachedData    Any partial report data that was returned from
+     *                              generateFileReport during the run.
+     * @param int    $totalFiles    Total number of files processed during the run.
+     * @param int    $totalErrors   Total number of errors found during the run.
+     * @param int    $totalWarnings Total number of warnings found during the run.
+     * @param int    $totalFixable  Total number of problems that can be fixed.
+     * @param bool   $showSources   Show sources?
+     * @param int    $width         Maximum allowed line width.
+     * @param bool   $interactive   Are we running in interactive mode?
+     * @param bool   $toScreen      Is the report being printed to screen?
+     *
+     * @return void
+     */
+    public function generate(
+        $cachedData,
+        $totalFiles,
+        $totalErrors,
+        $totalWarnings,
+        $totalFixable,
+        $showSources=false,
+        $width=80,
+        $interactive=false,
+        $toScreen=true
+    ) {
+        $lines = explode(PHP_EOL, $cachedData);
+        array_pop($lines);
+
+        if (empty($lines) === true) {
+            return;
+        }
+
+        // First collect the accumulated timings.
+        $timings        = [];
+        $totalSniffTime = 0;
+        foreach ($lines as $line) {
+            $parts      = explode('>>', $line);
+            $sniffClass = $parts[0];
+            $time       = $parts[1];
+
+            if (isset($timings[$sniffClass]) === false) {
+                $timings[$sniffClass] = 0;
+            }
+
+            $timings[$sniffClass] += $time;
+            $totalSniffTime       += $time;
+        }
+
+        // Next, tidy up the sniff names and determine max needed column width.
+        $totalTimes   = [];
+        $maxNameWidth = 0;
+        foreach ($timings as $sniffClass => $secs) {
+            $sniffCode    = Common::getSniffCode($sniffClass);
+            $maxNameWidth = max($maxNameWidth, strlen($sniffCode));
+            $totalTimes[$sniffCode] = $secs;
+        }
+
+        // Leading space + up to 12 chars for the number.
+        $maxTimeWidth = 13;
+        // Leading space, open parenthesis, up to 5 chars for the number, space + % and close parenthesis.
+        $maxPercWidth = 10;
+        // Calculate the maximum width available for the sniff name.
+        $maxNameWidth = min(($width - $maxTimeWidth - $maxPercWidth), max(($width - $maxTimeWidth - $maxPercWidth), $maxNameWidth));
+
+        arsort($totalTimes);
+
+        echo PHP_EOL."\033[1m".'PHP CODE SNIFFER SNIFF PERFORMANCE REPORT'."\033[0m".PHP_EOL;
+        echo str_repeat('-', $width).PHP_EOL;
+        echo "\033[1m".'SNIFF'.str_repeat(' ', ($width - 31)).'TIME TAKEN (SECS)     (%)'."\033[0m".PHP_EOL;
+        echo str_repeat('-', $width).PHP_EOL;
+
+        // Mark sniffs which take more than twice as long as the average processing time per sniff
+        // in orange and when they take more than three times as long as the average,
+        // mark them in red.
+        $avgSniffTime       = ($totalSniffTime / count($totalTimes));
+        $doubleAvgSniffTime = (2 * $avgSniffTime);
+        $tripleAvgSniffTime = (3 * $avgSniffTime);
+
+        $format        = "%- {$maxNameWidth}.{$maxNameWidth}s % 12.6f (% 5.1f %%)".PHP_EOL;
+        $formatBold    = "\033[1m%- {$maxNameWidth}.{$maxNameWidth}s % 12.6f (% 5.1f %%)\033[0m".PHP_EOL;
+        $formatWarning = "%- {$maxNameWidth}.{$maxNameWidth}s \033[33m% 12.6f (% 5.1f %%)\033[0m".PHP_EOL;
+        $formatError   = "%- {$maxNameWidth}.{$maxNameWidth}s \033[31m% 12.6f (% 5.1f %%)\033[0m".PHP_EOL;
+
+        foreach ($totalTimes as $sniff => $time) {
+            $percent = round((($time / $totalSniffTime) * 100), 1);
+
+            if ($time > $tripleAvgSniffTime) {
+                printf($formatError, $sniff, $time, $percent);
+            } else if ($time > $doubleAvgSniffTime) {
+                printf($formatWarning, $sniff, $time, $percent);
+            } else {
+                printf($format, $sniff, $time, $percent);
+            }
+        }
+
+        echo str_repeat('-', $width).PHP_EOL;
+        printf($formatBold, 'TOTAL SNIFF PROCESSING TIME', $totalSniffTime, 100);
+
+        $runTime   = (Timing::getDuration() / 1000);
+        $phpcsTime = ($runTime - $totalSniffTime);
+
+        echo PHP_EOL.str_repeat('-', $width).PHP_EOL;
+        printf($format, 'Time taken by sniffs', $totalSniffTime, round((($totalSniffTime / $runTime) * 100), 1));
+        printf($format, 'Time taken by PHPCS runner', $phpcsTime, round((($phpcsTime / $runTime) * 100), 1));
+
+        echo str_repeat('-', $width).PHP_EOL;
+        printf($formatBold, 'TOTAL RUN TIME', $runTime, 100);
+        echo str_repeat('-', $width).PHP_EOL;
+
+    }//end generate()
+
+
+}//end class

src/Util/Timing.php

@@ -40,6 +40,51 @@ public static function startTiming()
     }//end startTiming()
 
 
+    /**
+     * Get the duration of the run up to "now".
+     *
+     * @return int Duration in microseconds.
+     */
+    public static function getDuration()
+    {
+        if (self::$startTime === null) {
+            // Timing was never started.
+            return 0;
+        }
+
+        return ((microtime(true) - self::$startTime) * 1000);
+
+    }//end getDuration()
+
+
+    /**
+     * Convert a duration in microseconds to a human readable duration string.
+     *
+     * @param int $duration Duration in microseconds.
+     *
+     * @return string
+     */
+    public static function getHumanReadableDuration($duration)
+    {
+        $timeString = '';
+        if ($duration > 60000) {
+            $mins       = floor($duration / 60000);
+            $secs       = round((fmod($duration, 60000) / 1000), 2);
+            $timeString = $mins.' mins';
+            if ($secs !== 0) {
+                $timeString .= ", $secs secs";
+            }
+        } else if ($duration > 1000) {
+            $timeString = round(($duration / 1000), 2).' secs';
+        } else {
+            $timeString = round($duration).'ms';
+        }
+
+        return $timeString;
+
+    }//end getHumanReadableDuration()
+
+
     /**
      * Print information about the run.
      *
@@ -60,23 +105,11 @@ public static function printRunTime($force=false)
             return;
         }
 
-        $time = ((microtime(true) - self::$startTime) * 1000);
-
-        if ($time > 60000) {
-            $mins = floor($time / 60000);
-            $secs = round((fmod($time, 60000) / 1000), 2);
-            $time = $mins.' mins';
-            if ($secs !== 0) {
-                $time .= ", $secs secs";
-            }
-        } else if ($time > 1000) {
-            $time = round(($time / 1000), 2).' secs';
-        } else {
-            $time = round($time).'ms';
-        }
+        $duration = self::getDuration();
+        $duration = self::getHumanReadableDuration($duration);
 
         $mem = round((memory_get_peak_usage(true) / (1024 * 1024)), 2).'MB';
-        echo "Time: $time; Memory: $mem".PHP_EOL.PHP_EOL;
+        echo "Time: $duration; Memory: $mem".PHP_EOL.PHP_EOL;
 
         self::$printed = true;