rectorphp / rector

Instant Upgrades and Automated Refactoring of any PHP 5.3+ code
https://getrector.com
MIT License
8.73k stars 686 forks source link

[ERROR] Rector timeout after upgrading it to 0.19.0 #8403

Closed vinceAmstoutz closed 10 months ago

vinceAmstoutz commented 10 months ago

Bug Report

Subject Details
Rector version 0.19.0

Since the upgrade of rector (from 0.18.13 to 0.19.0) I have this big error : image

I also try to folow these intructions without sucess https://getrector.com/documentation/troubleshooting-parallel

Minimal PHP Code Causing Issue

  1. Edit composer.json file
{
    "require-dev": {
        "rector/rector": "^0.19.0"
    }
}
  1. Run composer update

This is the 1st time I've had this at an rector update.

Expected Behaviour

Job passing like in version 0.18.13, just before upgrading rector to the 0.19.0

samsonasik commented 10 months ago

Rector 0.19.0 parallel config is default to 60, 32, 20 value, You can update to old config:

$rectorConfig->parallel(120, 16, 15);
TomasVotruba commented 10 months ago

Thanks for reporting :+1:

What is the output when you disable parallel?

See https://github.com/rectorphp/rector/issues/8396#issuecomment-1884616501 as well, there might be costly loops that were not visible before.

vinceAmstoutz commented 10 months ago

Rector 0.19.0 parallel config is default to 60, 32, 20 value, You can update to old config:

$rectorConfig->parallel(120, 16, 15);

I have this with your proposition image

samsonasik commented 10 months ago

I apply some performance improvement on latest dev-main, could you try update to "rector/rector": "dev-main" ?

If still happen, we may need a github repo to reproduce the issue, try use $rectorConfig->disableParallel() to verify the issue on specific rule or in parallel process.

TomasVotruba commented 10 months ago

I've updated the timeout to 120 and released 0.19.1 :+1:

TomasVotruba commented 10 months ago

@vinceAmstoutz At first glance it's suspicious that your process of 800 files times out so soon. To compare Rector codebase has 2100 files and it finishes in about 40 seconds as whole.

If you can provide costly combination of rules and paths, we could look at the performance. We use this approach to find the files and rules - https://tomasvotruba.com/blog/2021/02/01/effective-debug-tricks-narrow-scoping/

lugosium commented 10 months ago

FYI, i have 681 files and increased timeout by 60 seconds every time it died. It's working now with 360 seconds. Before, it took about 30 seconds. I looked the release yesterday but don't find anything yet.

TomasVotruba commented 10 months ago

I see. We'll need to find out, which commit broke this for you, to avoid shooting in the dark.

Could you try few commits before 0.19.0 release and see, how it affects the speed? https://github.com/rectorphp/rector/commits/main/

image

{
    "require": {
         "rector/rector": "dev-main#dbbdf42842490a97fd9c35e4e899192e1b06f10b"
    }
}
composer update
lugosium commented 10 months ago

I will 👍

vinceAmstoutz commented 10 months ago

Thanks for reporting 👍

What is the output when you disable parallel?

See #8396 (comment) as well, there might be costly loops that were not visible before.

@TomasVotruba When I disable parallel I have this after almost 20 minutes (before this release it was 30s or 1min maximum) image

But with $rectorConfig->parallel(120, 16, 15); and the --debug option I have this output image

And with the default value & the --debug option I have this output image

I will try soon on dev-main and what you have given more recently.

samsonasik commented 10 months ago

On same disableParallel(), that seems impossible you get 1 minutes as well, while 0.19.x you got 20 minutes.

I guess 1 minutes in previous version 0.18.x, you are using parallel.

Comparing parallel vs disableParallel() is expected got many times slower.

TomasVotruba commented 10 months ago

@vinceAmstoutz Thanks for reaching out. We need to find out what commit caused this.

Could you give this approach a try and see which commit made the performance drop? https://github.com/rectorphp/rector/issues/8403#issuecomment-1893430494

samsonasik commented 10 months ago

It also possibly issue on phpstan itself, start from 1.10.55, The PhpDocNode::getRequireExtendsTagValues() is exists since last PHPStan which require the latest https://github.com/phpstan/phpdoc-parser so it can possibly from there.

samsonasik commented 10 months ago

To exactly compare, the both compares need exists:

1 Disable Parallel

0.18.x : disableParallel() : x minutes y seconds
0.19.x : disableParallel() : x minutes y seconds
dev-main : disableParallel() : x minutes y seconds

2. Enable Parallel

0.18.x : parallel() : x minutes y seconds
0.19.x : parallel(x, y, z)  : x minutes y seconds
dev-main : parallel(x, y, z)  : x minutes y seconds

We also needs a reproducible repo, that we can found a possible bottleneck, as it can from Rector or phpstan itself.

vinceAmstoutz commented 10 months ago

On same disableParallel(), that seems impossible you get 1 minutes as well, while 0.19.x you got 20 minutes.

I guess 1 minutes in previous version 0.18.x, you are using parallel.

Comparing parallel vs disableParallel() is expected got many times slower.

No, before these tests, my configuration was as follows

<?php

declare(strict_types=1);

use Rector\Config\RectorConfig;
use Rector\Doctrine\Set\DoctrineSetList;
use Rector\Set\ValueObject\LevelSetList;
use Rector\Set\ValueObject\SetList;
use Rector\Symfony\Set\SymfonyLevelSetList;
use Rector\Symfony\Set\SymfonySetList;

return static function (RectorConfig $rectorConfig): void {
    $rectorConfig->paths([
        __DIR__.'/src',
        __DIR__.'/tests',
    ]);

    $rectorConfig->importNames();

    $rectorConfig->sets([
        SetList::DEAD_CODE,
        SetList::CODING_STYLE,
        SetList::CODE_QUALITY,
        SetList::EARLY_RETURN,
        SetList::INSTANCEOF,
        SetList::STRICT_BOOLEANS,
        SetList::TYPE_DECLARATION,
        SetList::PHP_83,
        LevelSetList::UP_TO_PHP_83,
        SymfonySetList::SYMFONY_CODE_QUALITY,
        SymfonySetList::SYMFONY_64,
        SymfonySetList::SYMFONY_CONSTRUCTOR_INJECTION,
        SymfonyLevelSetList::UP_TO_SYMFONY_63,
        DoctrineSetList::DOCTRINE_CODE_QUALITY,
    ]);
};
vinceAmstoutz commented 10 months ago

@vinceAmstoutz Thanks for reaching out. We need to find out what commit caused this.

Could you give this approach a try and see which commit made the performance drop? #8403 (comment)

Yes @TomasVotruba I will soon as possible

samsonasik commented 10 months ago

parallel() is enabled by default, even you don't enable it, see

https://github.com/rectorphp/rector/blob/0d611d897ad7ea3456d926d654615bdd5ef0bf3b/config/config.php#L15

so 1 minutes is expected.

vinceAmstoutz commented 10 months ago

To exactly compare, the both compares need exists:

1 Disable Parallel

0.18.x : disableParallel() : x minutes y seconds
0.19.x : disableParallel() : x minutes y seconds
dev-main : disableParallel() : x minutes y seconds

2. Enable Parallel

0.18.x : parallel() : x minutes y seconds
0.19.x : parallel(x, y, z)  : x minutes y seconds
dev-main : parallel(x, y, z)  : x minutes y seconds

We also needs a reproducible repo, that we can found a possible bottleneck, as it can from Rector or phpstan itself.

@samsonasik I'll try what @TomasVotruba suggests here https://github.com/rectorphp/rector/issues/8403#issuecomment-1893430494 and if that's not enough, I'll try to make an accessible repo because it's a proprietary project.

vinceAmstoutz commented 10 months ago

@samsonasik But there's no doubt that I was in 0.18.13 before, and if you insist I can send you the proof, along with screenshots of the CI, which took no longer than 2min/2min30s.

image

samsonasik commented 10 months ago

sure, but 20 times slower is impossible with same disableParallel() config, that must be parallel() vs disableParallel(), which parallel() is enabled by default, that's why it is 1 minutes vs 20 minutes.

vinceAmstoutz commented 10 months ago

sure, but 20 times slower is impossible with same disableParallel() config, that must be parallel() vs disableParallel(), which parallel() is enabled by default, that's why it is 1 minutes vs 20 minutes.

Maybe, but whatever I try, it's much slower and doesn't work... 😕

samsonasik commented 10 months ago

I used it a very big projects, scan 4000+ files, with many files has 3000/4000+ lines, that's not that slow, and only take 7 minutes 50 seconds which already cut by build docker, composer, etc, and clean up things.

so without reproducible repo, we probably can't help further.

you're comparing disableParallel() vs default paralallel(), it probably slower, which can be from Rector or PHPStan 1.10.55 itself, but 20 times slower is impossible, except you can prove it in a repo :)

vinceAmstoutz commented 10 months ago

I used it a very big projects, scan 4000+ files, with many files has 3000/4000+ lines, that's not that slow, and only take 7 minutes 50 seconds which already cut by build docker, composer, etc, and clean up things.

so without reproducible repo, we probably can't help further.

you're comparing disableParallel() vs default paralallel(), it probably slower, which can be from Rector or PHPStan 1.10.55 itself, but 20 times slower is impossible, except you can prove it in a repo :)

As I have already say, I will testing all possibilities soon as you describe here after testing what @TomasVotruba says. If we need more I will do my best to reproduce that for you. If not, we could make a call so that you can test live?

samsonasik commented 10 months ago

Thank you, as short, disableParallel() must be compared with same disableParallel() config, and parallel() need to be compared with parallel() config.

I am not sure if I have time to call on this, it is better to have reproducible repo :)

vinceAmstoutz commented 10 months ago

@samsonasik So for now, I've got these benchmarks to share with you before testing @TomasVotruba suggestions

Disable Parallel Parallel (60, 30, 20) Parallel (120, 16, 15)
0.18.13 3min 8s 21ms 1min 15s 523ms 1min 2s 274ms
0.19.0 16min 54s 65ms 3 min 1s 202ms -> timeout 4 min 3s 717ms -> timeout
dev-main 14min 25s 850ms 2 min 56s 362ms -> timeout 2min 50s 267ms -> timeout

I also have screenshots of all the measurements I took if you need them.

samsonasik commented 10 months ago

@vinceAmstoutz thank you, that's seems strange, I create a PR to add false default autoload to disable autoload on class_alias at:

for deprecating Rector\Core subnamespace.

Could you try copy src/core_namespace_aliases.php that uses false default autoload at:

https://raw.githubusercontent.com/rectorphp/rector-src/add-false-autoload/src/core_namespace_aliases.php

to your vendor/rector/rector/src/core_namespace_aliases.php and verify if that increase the performance?

vinceAmstoutz commented 10 months ago

@vinceAmstoutz thank you, that's seems strange, I create a PR to add false default autoload to disable autoload on class_alias at:

* [[Autoload] Add false value for autoload on class_alias() on core_namespace_aliases.php rector-src#5474](https://github.com/rectorphp/rector-src/pull/5474)

for deprecating Rector\Core subnamespace.

Could you try copy src/core_namespace_aliases.php that uses false default autoload at:

https://raw.githubusercontent.com/rectorphp/rector-src/add-false-autoload/src/core_namespace_aliases.php

to your vendor/rector/rector/src/core_namespace_aliases.php and verify if that increase the performance?

@samsonasik I've test on dev-main it's a bit faster but I also get a big error when I use the default version of parallel config when I run rector with the --clear-cache option

image

samsonasik commented 10 months ago

Thank you, at least it faster, I will merge the PR.

I will looking on other area that can improve performance.

Looking at the setlist you have, it seems you have huge of collection of setlist, could you narrow down and possibly found a rules that have bottleneck? Otherwise, we may need a reproducible repo.

vinceAmstoutz commented 10 months ago

Thank you, at least it faster, I will merge the PR.

I will looking on other area that can improve performance.

Looking at the setlist you have, it seems you have huge of collection of setlist, could you narrow down and possibly found a rules that have bottleneck? Otherwise, we may need a reproducible repo.

@samsonasik After many combination tests, it works with my rector configuration if I don't use these rules:

<?php

declare(strict_types=1);

use Rector\Config\RectorConfig;
use Rector\Doctrine\Set\DoctrineSetList;
use Rector\Set\ValueObject\LevelSetList;
use Rector\Set\ValueObject\SetList;
use Rector\Symfony\Set\SymfonyLevelSetList;
use Rector\Symfony\Set\SymfonySetList;

return static function (RectorConfig $rectorConfig): void {
    $rectorConfig->paths([
        __DIR__.'/src',
        __DIR__.'/tests',
    ]);

    $rectorConfig->importNames();

    $rectorConfig->sets([
        SetList::DEAD_CODE,
        SetList::CODING_STYLE,
        SetList::CODE_QUALITY,
        SetList::EARLY_RETURN,
        SetList::INSTANCEOF,
        SetList::STRICT_BOOLEANS,
        SetList::TYPE_DECLARATION,
        SetList::PHP_83,
        LevelSetList::UP_TO_PHP_83,
//        SymfonySetList::SYMFONY_CODE_QUALITY,
//        SymfonySetList::SYMFONY_64,
        SymfonySetList::SYMFONY_CONSTRUCTOR_INJECTION,
//        SymfonyLevelSetList::UP_TO_SYMFONY_64,
        DoctrineSetList::DOCTRINE_CODE_QUALITY,
    ]);
};
samsonasik commented 10 months ago

Thank you, that seems on specific symfony rules, see changes on latest rector-symfony diffs

https://github.com/rectorphp/rector-symfony/commits/main/

if you found something fishy, feel free to provide a patch ;)

TomasVotruba commented 10 months ago

@vinceAmstoutz Thanks for more debug info. Indeed it's not best practise to use UP_TO_* sets in rector.php longer than is their single-run. They run dozens of rules with very complex logic, as it take to get from Symfony 2 to 7. It's like running a Tesla control and checking all elements available since the first horse ride :)

See section 3: https://getrector.com/blog/5-common-mistakes-in-rector-config-and-how-to-avoid-them

I recommend to run those just once and remove those :+1:

We got similar feedback from various project, seeing the Symfony "level up to" approach is not the best, neither practical to use. I'll think about how to deprecate those to avoid similar hustle for other users.

Thank you

TomasVotruba commented 10 months ago

@vinceAmstoutz See https://github.com/rectorphp/rector-src/pull/5477

Let me know if we can improve the feedback :+1:

Thank you so much for your input. It help us to improve Rector further and fix the glitch to improve DX for other to come :pray:

vinceAmstoutz commented 10 months ago

@vinceAmstoutz Thanks for more debug info. Indeed it's not best practise to use UP_TO_* sets in rector.php longer than is their single-run. They run dozens of rules with very complex logic, as it take to get from Symfony 2 to 7. It's like running a Tesla control and checking all elements available since the first horse ride :)

See section 3: https://getrector.com/blog/5-common-mistakes-in-rector-config-and-how-to-avoid-them

I recommend to run those just once and remove those 👍

We got similar feedback from various project, seeing the Symfony "level up to" approach is not the best, neither practical to use. I'll think about how to deprecate those to avoid similar hustle for other users.

Thank you

@TomasVotruba Thank you for your time and explanations. I learned a lot about the best practice of the rector, I will read your book very soon to go further.

At the moment, it doesn't work with this (without UP_TO_* sets) & only if I combined this with this tips

$rectorConfig->sets([
        SetList::DEAD_CODE,
        SetList::CODING_STYLE,
        SetList::CODE_QUALITY,
        SetList::EARLY_RETURN,
        SetList::INSTANCEOF,
        SetList::STRICT_BOOLEANS,
        SetList::TYPE_DECLARATION,
        SetList::PHP_83,
        SymfonySetList::SYMFONY_CODE_QUALITY,
        SymfonySetList::SYMFONY_64,
        SymfonySetList::SYMFONY_CONSTRUCTOR_INJECTION,
        DoctrineSetList::DOCTRINE_CODE_QUALITY,
    ]);

But if I comment SymfonySetList::SYMFONY_CODE_QUALITY & SymfonySetList::SYMFONY_64 combined with the same tips , it's works (if I only comment one it's not enough to succeed)!

Have you a solution?

vinceAmstoutz commented 10 months ago

@vinceAmstoutz See rectorphp/rector-src#5477

Let me know if we can improve the feedback 👍

Thank you so much for your input. It help us to improve Rector further and fix the glitch to improve DX for other to come 🙏

@TomasVotruba No, it's perfect! Thank you so much for all you do for the PHP community 🙏🐘

vinceAmstoutz commented 10 months ago

@TomasVotruba @samsonasik I've found a solution that's not so great, adding this $rectorConfig->parallel(180);

AtCliffUnderline commented 9 months ago

have same problem here with phpstan/phpstan (1.10.57) and rector/rector (0.19.5). Timeouts with parallel,Up to 4x slow without parallel