[bug] StatementsVolatileCache a cause of large memory usage when cache not in use

[dkarlovi]

When implementing #9889, a discussion about resource usage vs performance pointed me to investigate why Psalm is using as much memory as it is. It seems StatementsVolatileCache is at fault, it can keep a lot of memory in use, making Psalm even unusable in some cases with very very large memory footprint (@orklah claims 8GB+).

It seems there would be a better way to find a tradeoff here, Psalm shouldn't hog all the memory.

Suggested fixes in Symfony Slack:

1. @dantleech - add a TTL to the cache entries
2. @ciaranmcnulty - Least Recently Used policy (this seems to already be implemented)
3. Gzip content of cache (in which case it also needs marshalling)
4. write content into php:temp (this seems like the existing cache system)

Maybe we could even consider what happens if we disable this cache fully? It doesn't seem to do that much, but I didn't test that throughly.

[psalm-github-bot]

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

[orklah]

Response to #9889 (comment) :

I certainly got interesting results. I'm not sure those results can be generalized (because they were done in my work station with 16G of memory, while I was working and with a big old legacy project) but here they are:

$max_size = 0
Checks took 1,402.68 seconds and used 5,917.490MB of memory

$max_size = 1
Checks took 1,452.14 seconds and used 5,922.565MB of memory

$max_size = 1024
Checks took 1,863.02 seconds and used 7,196.673MB of memory

$max_size = 2048
Checks took 2,091.63 seconds and used 7,692.036MB of memory

$max_size = 4096 (default)
Crash because my memory_limit was 8Gb. Likely would have used 8.4GB like it does on our CI

So, in my specific case, this volatile cache is detrimental both in time AND memory. It's likely because it forces my OS to use the swap file to store excess memory usage and degrades time performance with IO on hard drive (it's an SSD)

Note that everything was run with --no-cache, because I never could run Psalm with cache enabled (maybe I should try again with this change, though I'm pretty sure the issue is elsewhere)

[dkarlovi]

@orklah the same effect is noticeable in Psalm's self-analysis. IMO it might make sense to see if removing this class completely would make an impact since you might be better off loading files on demand from disk cache instead of keeping all this in memory.

@muglug could you spare some insight here?

[dkarlovi]

Note that everything was run with --no-cache, because I never could run Psalm with cache enabled (maybe I should try again with this change, though I'm pretty sure the issue is elsewhere)

Try max_size=0 and enabling cache, maybe it works 🤞

[LiamKearn]

I took a look at this one without thinking about solutions or reading through the code properly.

PHP's GC not being effective with the LRU cache isn't an issue here memory wise, we're only caching the top nodes of the AST for each file and the AST is not cyclic. I checked this with a debug_zval_dump and the only ref counts I could see above 1 behind a separate reference usually PhpParser\Node\Name::parts and other such strings. It is a bit weird that they show as having multiple references instead of displaying "interned" instead of their ref count, not a big fruit here anyways.

It's worth noting that storing each file's ASTs separately is obviously going to going to allocate more than it needs because it's not a "one-file" strategy like C or rust's module based parser where details such as namespaces and symbols can be stored once per declaration. For example I'm guessing we might parse and store namespace A\B twice between two files. In short there is not interning between each cache item (an item being a collection of a file's top level nodes) so it's a bit wasteful there. That being said implementing a multi-file parsing and caching strategy is probably a going to be specific to each project setup so i'm not sure any would already exist.

However phpparser notes it might be slowed down by GC a fair bit, as far as I can see there is no disabling of the GC during parsing which is probably more effort than it's worth as an optimisation. You can read more of that following from the same link as above here.

It's worth noting that Psalm\Internal\Provider\StatementsVolatileCache is a per-process cache that is seems to be utilised by multiple threads (seperately?). It looks as though two threads can pickup the same work.

For example make the following patch:

diff --git a/src/Psalm/Internal/Provider/StatementsProvider.php b/src/Psalm/Internal/Provider/StatementsProvider.php
index 6393cd34c..74980942d 100644
--- a/src/Psalm/Internal/Provider/StatementsProvider.php
+++ b/src/Psalm/Internal/Provider/StatementsProvider.php
@@ -133,9 +133,12 @@ class StatementsProvider
             || (!$config->isInProjectDirs($file_path) && strpos($file_path, 'vendor'))
         ) {
             $cache_key = "{$file_content_hash}:{$analysis_php_version_id}";
+            fprintf(STDERR, "\nr{$cache_key}\n");
             if ($this->statements_volatile_cache->has($cache_key)) {
+                fprintf(STDERR, "\nh{$cache_key}\n");
                 return $this->statements_volatile_cache->get($cache_key);
             }
+            fprintf(STDERR, "\nm{$cache_key}\n");
 
             $progress->debug('Parsing ' . $file_path . "\n");

Grab a set of stats for threading and otherwise, filtering out fancy output to get a list of cache requests, hits and misses denoted by the first character. (vimeo/psalm/commit/2c50745d8f6b4845905e9f286f0e8d4be95d2f6d used here)

./psalm --no-cache --threads=20 2>20threadsnocache && sed -i '/\([%|░]\|^$\)/d;1,2d' 20threadsnocache

./psalm --no-cache --threads=1 2>1threadnocache && sed -i '/\([%|░]\|^$\)/d;1,2d' 1threadnocache

Save the following script (filter.php) to filter for misses:

<?php

$cachestats = [];

while (($line = fgets(STDIN)) !== false) {
    $key = substr($line, 2);
    if (!isset($cachestats[$key])) $cachestats[$key] = [
        'r' => 0,
        'h' => 0,
        'm' => 0,
    ];

    $op = substr($line, 0, 1);
    if ($op === 'r') $cachestats[$key]['r'] += 1;
    if ($op === 'h') $cachestats[$key]['h'] += 1;
    if ($op === 'm') $cachestats[$key]['m'] += 1;
}

// Default to filtering for
$countfilter = intval($argv[1] ?? 2); // 2 or more
$opfilter = $argv[2] ?? 'm'; // misses

$opcount = 0;
foreach ($cachestats as $set)
    if ($set[$opfilter] >= $countfilter)
        $opcount++;

$opmap = ['m' => 'misses', 'h' => 'hits', 'r' => 'requests'];
echo "$opcount keys with $countfilter or more {$opmap[$opfilter]}" . PHP_EOL;

Checking for seemingly redundant work?

$ cat 20threadsnocache | php filter.php

58 keys with 2 or more misses

Given this is 20 threads it's very spread out:

$ cat 20threadsnocache | php index.php 5 m

23 keys with 5 or more misses

Now to confirm our suspect of threading by seeing if the same miss rate is present on a single thread:

$ cat 1threadnocache | php index.php

0 keys with 2 or more misses

And confirming we are doing the same amount of work:

$ cat 1threadnocache | php index.php 1 r

2226 keys with 1 or more requests

$ cat 20threadsnocache | php index.php 1 r

2226 keys with 1 or more requests

And finally just to be clear multi-threading does hit the cache but I'm not aware of if this is a single thread hitting it's own cache or some sort of sharing (I didn't look at the threading code):

$ cat 20threadsnocache | php index.php 2 h

130 keys with 2 or more hits

I suspect I've mucked up somewhere because that is definitely doesn't sound right but maybe it's useful 😄

---

Psalm\Internal\Provider\StatementsVolatileCache definitely seems to be useless memory usage wise when multi-threading.

Here are some numbers for that using

• Beefy workstation, Ubuntu, threadripper (24c) @ 3.800GHz, 31946MiB
• ./psalm --no-cache --threads=x
• 2c50745

Disabling StatementsVolatileCache with:

diff --git a/src/Psalm/Internal/Provider/StatementsProvider.php b/src/Psalm/Internal/Provider/StatementsProvider.php
index 6393cd34c..97642c352 100644
--- a/src/Psalm/Internal/Provider/StatementsProvider.php
+++ b/src/Psalm/Internal/Provider/StatementsProvider.php
@@ -143,7 +143,7 @@ class StatementsProvider

            $stmts = self::parseStatements($file_contents, $analysis_php_version_id, $has_errors, $file_path);

-            $this->statements_volatile_cache->set($cache_key, $stmts);
+            // $this->statements_volatile_cache->set($cache_key, $stmts);

            return $stmts;
        }

StatementsVolatileCache?	Threads	Runtime	Mem
	1	42.51s	642.262MB
yes	1	39.17s	1,233.968MB
	20	12.24s	685.138MB
yes	20	12.44s	911.134MB

Hopefully some things to debunk or that could be improved here :)

[dkarlovi]

Psalm\Internal\Provider\StatementsVolatileCache definitely seems to be useless memory usage wise when multi-threading.

This is a good takeaway. Even when not multi-threading, the runtime difference is minor, while the memory difference is major. It seems like this cache could be removed from Psalm completely to be able to focus on the file-based cache all threads can equally use.

[dkarlovi]

@orklah did you get a chance to test on your mega-codebase when this cache is disabled, but file cache enabled by any chance?

[orklah]

@orklah did you get a chance to test on your mega-codebase when this cache is disabled, but file cache enabled by any chance?

Yeah, that makes no difference. With cache enabled, Psalm doesn't even make it to the step where there's a progressbar. It stays in "scan files" mode.

BTW, every test I did, I do in 1 thread. Using multiple threads actually makes Psalm longer for me :p

[LiamKearn]

Psalm\Internal\Provider\StatementsVolatileCache definitely seems to be useless memory usage wise when multi-threading.

Debunked! I slept on this then realised I blindly trusted psalm's memory usage output only to click on the github notifications today, search the codebase and realise it's memory_get_peak_usage!

Regardless given the cache is definitely not shared between fcntl_fork procs so it's likely not that efficient but the numbers above are gobeldygook from the parent proc not reflective of actual system memory usage.

Here is the output confirm there are no duplicate cache misses for each proc:

[PID: 56313] 0 keys with 2 or more misses
[PID: 56314] 0 keys with 2 or more misses
[PID: 56315] 0 keys with 2 or more misses
[PID: 56316] 0 keys with 2 or more misses
[PID: 56317] 0 keys with 2 or more misses
[PID: 56318] 0 keys with 2 or more misses
[PID: 56319] 0 keys with 2 or more misses
[PID: 56341] 0 keys with 2 or more misses
[PID: 56342] 0 keys with 2 or more misses
[PID: 56343] 0 keys with 2 or more misses
[PID: 56344] 0 keys with 2 or more misses
[PID: 56345] 0 keys with 2 or more misses
[PID: 56346] 0 keys with 2 or more misses
[PID: 56347] 0 keys with 2 or more misses
[PID: 56348] 0 keys with 2 or more misses
[PID: 56349] 0 keys with 2 or more misses
[PID: 56350] 0 keys with 2 or more misses
[PID: 56351] 0 keys with 2 or more misses
[PID: 56352] 0 keys with 2 or more misses
[PID: 56353] 0 keys with 2 or more misses
[PID: 56354] 0 keys with 2 or more misses
[PID: 56355] 0 keys with 2 or more misses
[PID: 56356] 0 keys with 2 or more misses
[PID: 56357] 0 keys with 2 or more misses
[PID: 56358] 0 keys with 2 or more misses
[PID: 56359] 0 keys with 2 or more misses
[PID: 56360] 0 keys with 2 or more misses

We should just be using the file cache really. Pool caching multiple full ASTs in memory is ridiculous. If they were actually ref counted it would make sense.

[dkarlovi]

In the meantime PHPStan author said in Symfony Slack PHPStan doesn't use any sort of AST cache at all, it does it all live. :)

Psalm has two layers of cache for the same thing, wonder why that is.

[orklah]

Well, let's drop that then! If @muglug has some insight afterwards, reverting is always an option :)

[dkarlovi]

@LiamKearn it's all yours. 👼

[muglug]

This cache was originally added in #7876 — the blame falsely points to me because I think I used Git incorrectly when rebasing. This looks like a good change!

[muglug]

The original performance fix should have been opt-in, not opt-out. Without investigating too deeply, I assume those authors were encountering poor performance when analysing code written in a pre-composer-autoload style, where import and require statements are interepreted by Psalm in a necessarily order-dependent style. I originally added that behaviour (where the same PHP code is re-analyzed multiple times) to allow analysis of Wordpress core.