Show in debug how long a rule takes something like SlowRuleLog maybe

[alexander-schranz]

Feature Request

One of my projects is getting bigger and bigger and I need to increase the rector->parallel() configuration to get it run inside our gitlab CI runner.

Currently to run it in the CI I have to use:

$rectorConfig->parallel(480);

On 240 it did already run into timeouts and so we doubled it. Default is 120 seconds.

I think it would be nice if --debug maybe shows also which rules did take the most time to maybe check a specific rule if it can be optimized.

[staabm]

This might be helpful to debug slow projects

https://staabm.github.io/2023/05/10/how-to-debug-slow-rector-projects.html

[alexander-schranz]

I don't see any time outputted by --debug -vvv maybe something which was changed in 0.17 ? And so the outputted of your script is seems to stay empty: Slowest files

Updated: My error it was still on ^0.15 🙈 updating now to ^0.17.3

[staabm]

glad you figured it out. if you can reproduce somthing which is slow, feel free to send over a reproducing case.

I can look into it when time allows

[alexander-schranz]

Thx I currently can not reproduce my timeout issue locally (MacOS brew PHP 8.1) but on CI I still run into timeouts:

PS: I did put your script into copy&paste able oneliner to use it locally and in my CI script:

Rector Test:
    stage: Test
    needs:
        - Install # composer install
    image: php:8.1-cli
    script:
        - php vendor/bin/rector -vvv --debug --no-diffs | tee var/rector-slow-log.log
        # see: https://staabm.github.io/2023/05/10/how-to-debug-slow-rector-projects.html
        - |
           php -r 'declare(strict_types=1); $log = new SplFileObject("var/rector-slow-log.log"); $logs = []; $file = null; while (! $log->eof()) { $line = trim($log->fgets()); if ($line === \'\') { continue; } if (str_starts_with($line, \'[file]\')) { $file = $line; continue; } if ($file === null) { continue; } if (preg_match(\'/took (?<seconds>[\\d.]+) s/\', $line, $matches) === 1) { $accu = 0.0; if (array_key_exists($file, $logs)) { $accu = $logs[$file][0]; } $logs[$file] = [$accu + ((float) $matches[\'seconds\']), $file]; $file = null; } } usort($logs, fn(array $left, array $right) => $right[0] <=> $left[0]); $logs = array_slice($logs, 0, 100); echo "Slowest files" . PHP_EOL; foreach ($logs as $log) { echo sprintf("%.2f seconds: %s", $log[0], $log[1]) . PHP_EOL; }'
    artifacts:
        name: rector-slow-log
        expire_in: 72 hours
        when: always
        paths:
            - var/rector-slow-log.log

[alexander-schranz]

Currently sadly running into a Killed which sounds like a memory issue:

974/1050 [▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓░░░]  92%Killed
Script @php vendor/bin/rector process --dry-run handling the lint-rector event returned with error code 137

[staabm]

I know of a PHP 8.1.19 endless loop errors because of php-src bug in PHPStan. Maybe you are hit by the same bug?

[alexander-schranz]

Moved my problem into an own issue now: #8046.

This ticket is more about implemented something you have in https://staabm.github.io/2023/05/10/how-to-debug-slow-rector-projects.html

Why I personally would keep the Rules from the Log and show first which files and which rules take long. Maybe only keep rules in mind which take longer then a half second.

So maybe just sort the rector.log by time after finishing.

[samsonasik]

Hi @alexander-schranz , I am going to close it as that may probably cause another complexity of processing/logging. We have various performance improvement already on latest releases. Feel free to to try that.

Feel free to create a feature request PR if you think that reasonable.

[alexander-schranz]

@samsonasik Thx for the response I mostly will check them in a few weeks when it get a little bit calmer with the project where I did run into that issues.

[devnix]

As of today, --debug doesn't show the time it took for each file, and -v is not a valid option. I couldn't find any information on how to enable it; maybe it was removed?

[samsonasik]

-v is removed at PR

• [dx] help - omit explicit command name as no longer needed; remove verbosity option, use debug instead rector-src#7620

[github-actions]

This issue has been automatically locked because it has been closed for 150 days. Please open a new issue if you have a similar problem.