Hanging after 4.11.0

[sarelvdwalt]

When running psalm at version 4.10.0 - it runs successfully through our codebase.

./bin/psalm.phar --no-cache
Scanning files...
Analyzing files...

------------------------------
No errors found!
------------------------------

After upgrading of it (using the phar version) to 4.11.0 it is unable to finish the run (this has the same effect on 4.11.1, I used 4.11.0 to illustrate when this problem starts).
(Upgrade method: composer upgrade psalm/phar:4.11.0)

./bin/psalm.phar --no-cache
Scanning files...
Analyzing files...

████████████████████████████████████████████████████████▎░░░  5020 / 5345 (93%)

htop says psalm is still using 99% CPU, so it's still working - but I suspect it's in a loop somewhere.

I will try and narrow it down to what file / section of our code this is happening to - advice on what debug data to look at to try and narrow this down would be helpful.

[psalm-github-bot]

Hey @sarelvdwalt, can you reproduce the issue on https://psalm.dev ?

[weirdan]

psalm --threads=1 --debug may shed some light.

[sarelvdwalt]

Thanks - I have run that, and it's hanging while parsing the file. It appears, after trial and error, that it's something todo with a lot of constants in a large case statement. Here is the sample code (I cannot put it on psalm.dev 'cause it's too much code):

Here is a small file with only one constant and only one line in a switch statement:

<?php

class A
{
    const CONST_0000 = 0;

    public function testSomething($v)
    {
        switch ($v) {
            case self::CONST_0000:
                return 'found';
        }
    }
}

This results in a run-time of a couple of seconds:
time ./bin/psalm.phar --threads=1 --no-cache test.php

        3.37 real         2.14 user         1.20 sys

However, a file with a large amount of contants and switch-case elements, runs much, much slower:

<?php

class A
{
    const CONST_0000 = 0;
    const CONST_0001 = 1;
    const CONST_0002 = 2;
    const CONST_0003 = 3;
    const CONST_0004 = 4;
    const CONST_0005 = 5;
    const CONST_0006 = 6;
    const CONST_0007 = 7;
    const CONST_0008 = 8;
    const CONST_0009 = 9;
    const CONST_0010 = 10;
    const CONST_0011 = 11;
    const CONST_0012 = 12;
    const CONST_0013 = 13;
    const CONST_0014 = 14;
    const CONST_0015 = 15;
    const CONST_0016 = 16;
    const CONST_0017 = 17;
    const CONST_0018 = 18;
    const CONST_0019 = 19;

    const CONST_0020 = 20;
    const CONST_0021 = 21;
    const CONST_0022 = 22;
    const CONST_0023 = 23;
    const CONST_0024 = 24;
    const CONST_0025 = 25;
    const CONST_0026 = 26;
    const CONST_0027 = 27;
    const CONST_0028 = 28;
    const CONST_0029 = 29;

    const CONST_0030 = 30;
    const CONST_0031 = 31;
    const CONST_0032 = 32;
    const CONST_0033 = 33;
    const CONST_0034 = 34;
    const CONST_0035 = 35;
    const CONST_0036 = 36;
    const CONST_0037 = 37;
    const CONST_0038 = 38;
    const CONST_0039 = 39;
    const CONST_0040 = 40;
    const CONST_0041 = 41;
    const CONST_0042 = 42;
    const CONST_0043 = 43;
    const CONST_0044 = 44;
    const CONST_0045 = 45;
    const CONST_0046 = 46;
    const CONST_0047 = 47;
    const CONST_0048 = 48;
    const CONST_0049 = 49;
    const CONST_0050 = 50;
    const CONST_0051 = 51;
    const CONST_0052 = 52;
    const CONST_0053 = 53;
    const CONST_0054 = 54;
    const CONST_0055 = 55;
    const CONST_0056 = 56;
    const CONST_0057 = 57;
    const CONST_0058 = 58;
    const CONST_0059 = 59;
    const CONST_0060 = 60;
    const CONST_0061 = 61;
    const CONST_0062 = 62;
    const CONST_0063 = 63;
    const CONST_0064 = 64;
    const CONST_0065 = 65;
    const CONST_0066 = 66;
    const CONST_0067 = 67;
    const CONST_0068 = 68;
    const CONST_0069 = 69;
    const CONST_0070 = 70;
    const CONST_0071 = 71;
    const CONST_0072 = 72;
    const CONST_0073 = 73;
    const CONST_0074 = 74;
    const CONST_0075 = 75;
    const CONST_0076 = 76;
    const CONST_0077 = 77;
    const CONST_0078 = 78;
    const CONST_0079 = 79;
    const CONST_0080 = 80;
    const CONST_0081 = 81;
    const CONST_0082 = 82;
    const CONST_0083 = 83;
    const CONST_0084 = 84;
    const CONST_0085 = 85;
    const CONST_0086 = 86;
    const CONST_0087 = 87;
    const CONST_0088 = 88;
    const CONST_0089 = 89;
    const CONST_0090 = 90;
    const CONST_0091 = 91;
    const CONST_0092 = 92;
    const CONST_0093 = 93;
    const CONST_0094 = 94;
    const CONST_0095 = 95;
    const CONST_0096 = 96;
    const CONST_0097 = 97;
    const CONST_0098 = 98;
    const CONST_0099 = 99;
    const CONST_0100 = 100;
    const CONST_0101 = 101;
    const CONST_0102 = 102;
    const CONST_0103 = 103;
    const CONST_0104 = 104;
    const CONST_0105 = 105;
    const CONST_0106 = 106;
    const CONST_0107 = 107;
    const CONST_0108 = 108;

    public function testSomething($v)
    {
        switch ($v) {
            case self::CONST_0000:
            case self::CONST_0001:
            case self::CONST_0002:
            case self::CONST_0003:
            case self::CONST_0004:
            case self::CONST_0005:
            case self::CONST_0006:
            case self::CONST_0007:
            case self::CONST_0008:
            case self::CONST_0009:
            case self::CONST_0010:
            case self::CONST_0011:
            case self::CONST_0012:
            case self::CONST_0013:
            case self::CONST_0014:
            case self::CONST_0015:
            case self::CONST_0016:
            case self::CONST_0017:
            case self::CONST_0018:
            case self::CONST_0019:
            case self::CONST_0020:
            case self::CONST_0021:
            case self::CONST_0022:
            case self::CONST_0023:
            case self::CONST_0024:
            case self::CONST_0025:
            case self::CONST_0026:
            case self::CONST_0027:
            case self::CONST_0028:
            case self::CONST_0029:
            case self::CONST_0030:
            case self::CONST_0031:
            case self::CONST_0032:
            case self::CONST_0033:
            case self::CONST_0034:
            case self::CONST_0035:
            case self::CONST_0036:
            case self::CONST_0037:
            case self::CONST_0038:
            case self::CONST_0039:
            case self::CONST_0040:
            case self::CONST_0041:
            case self::CONST_0042:
            case self::CONST_0043:
            case self::CONST_0044:
            case self::CONST_0045:
            case self::CONST_0046:
            case self::CONST_0047:
            case self::CONST_0048:
            case self::CONST_0049:
            case self::CONST_0050:
            case self::CONST_0051:
            case self::CONST_0052:
            case self::CONST_0053:
            case self::CONST_0054:
            case self::CONST_0055:
            case self::CONST_0056:
            case self::CONST_0057:
            case self::CONST_0058:
            case self::CONST_0059:
            case self::CONST_0060:
            case self::CONST_0061:
            case self::CONST_0062:
            case self::CONST_0063:
            case self::CONST_0064:
            case self::CONST_0065:
            case self::CONST_0066:
            case self::CONST_0067:
            case self::CONST_0068:
            case self::CONST_0069:
            case self::CONST_0070:
            case self::CONST_0071:
            case self::CONST_0072:
            case self::CONST_0073:
            case self::CONST_0074:
            case self::CONST_0075:
            case self::CONST_0076:
            case self::CONST_0077:
            case self::CONST_0078:
            case self::CONST_0079:
            case self::CONST_0080:
            case self::CONST_0081:
            case self::CONST_0082:
            case self::CONST_0083:
            case self::CONST_0084:
            case self::CONST_0085:
            case self::CONST_0086:
            case self::CONST_0087:
            case self::CONST_0088:
            case self::CONST_0089:
            case self::CONST_0090:
            case self::CONST_0091:
            case self::CONST_0092:
            case self::CONST_0093:
            case self::CONST_0094:
            case self::CONST_0095:
            case self::CONST_0096:
            case self::CONST_0097:
            case self::CONST_0098:
            case self::CONST_0099:
                return 'found';
        }
    }
}

Results when running time ./bin/psalm.phar --threads=1 --no-cache test.php:

Scanning files...
Analyzing files...

░

------------------------------
No errors found!
------------------------------
2 other issues found.
# more output (not relevant to discussion)

Checks took 310.03 seconds and used 304.589MB of memory
299.95s user 4.21s system 97% cpu 5:11.78 total

[sarelvdwalt]

Then to test the same large file on composer 4.10.0:

composer upgrade psalm/phar:4.10.0

Lock file operations: 0 installs, 1 update, 0 removals
  - Downgrading psalm/phar (4.11.0 => 4.10.0)

time ./bin/psalm.phar --threads=1 --no-cache test.php

Scanning files...
Analyzing files...

░

------------------------------
No errors found!
------------------------------
2 other issues found.
You can display them with --show-info=true
------------------------------
Psalm can automatically fix 1 of these issues.
Run Psalm again with
--alter --issues=MissingReturnType --dry-run
to see what it can fix.
------------------------------

Checks took 3.10 seconds and used 81.827MB of memory
Psalm was unable to infer types in the codebase
./bin/psalm.phar --threads=1 --no-cache test.php  3.29s user 1.22s system 88% cpu 5.090 total

[orklah]

Thanks for the detailed report! I'll check that!

[sarelvdwalt]

Had some time to kill so I ran a couple scenario's through blackfire. The scenarios are:

• n amount of contants created
• same n amount of entries in the switch statement

So for example, you have this code, where n=2:

<?php
class A
{
    const CONST_0000 = 0;
    const CONST_0001 = 1;

    public function testSomething($v)
    {
        switch ($v) {
            case self::CONST_0000:
            case self::CONST_0001:
                return 'found';
        }
    }
}

It's a private blackfire account, so can't share the links, but here's a couple screengrabs, stating which n-number for each one:
1x constant: (n=1)

2x constants: (n=2)

3x constants: (n=3)

This is stable until 9 constants (n=9):

The moment we hit 10 constants (n=10) strpos (3rd highest call) starts to spike:

11x constants is significantly higher (n=11):

At 14 constants it's already out of hand (n=14)

Hope this helps :)

PS: Just want to re-iterate we are grateful for the work you folks are doing on this package!! ❤️

[orklah]

Wow, thanks! Mind checking on your graph what is the method that calls strpos this much?

EDIT: nvm, I think it's Clause.php