Performance issue with unit tests

[jonathanlermitage]

What happened?

Unit tests are very slow with plugin 2.2.0:

• with plugin 2.1.0: 10sec
• with plugin 2.2.0: 2min 30sec

I enter into the test phase, I see several Layout component org.jetbrains.plugins.emojipicker' has some nonexistent 'classPath' elements: 'plugins\emojipicker\lib\emojipicker.jar messages, which takes a lot of time, THEN, my unit tests are executed.
I also see this message two times at the configuration stage. I don't know if this is related to the issue.

Build scan: https://scans.gradle.com/s/4qoih2c35ezye

Relevant log output or stack trace

Build scan: https://scans.gradle.com/s/4qoih2c35ezye

Steps to reproduce

gradlew test

Gradle IntelliJ Plugin version

2.2.0

Gradle version

8.10.2

Operating System

Windows

Link to build, i.e. failing GitHub Action job

No response

[jonathanlermitage]

I can't provide the source code for my first build scan (commercial project, closed source), but
I tried again, with a small open-source plugin project, which contains no tests: https://github.com/jonathanlermitage/ij-devkit-helper

• plugin 2.1.0: gradlew test takes 2sec
• plugin 2.20 (update intelliJPlatform in gradle/libs.version): gradlew test takes 20sec, and I see the message about emojipicker.jar two times

[jonathanlermitage]

There is also a performance drop with the intellij-platform-plugin-template project, after having disabled the Gradle caches (org.gradle.configuration-cache and org.gradle.caching):

• with platfom plugin 2.1.0: ./gradlew clean test takes 20s
• with platfom plugin 2.2.1: ./gradlew clean test takes 1min. I don't know if this help, but with this version I also see several Failed to read bundled plugin 'plugins/cwm-plugin': Plugin 'plugins/cwm-plugin' is invalid: Invalid plugin descriptor 'plugin.xml'. The <release-version> parameter [2023300] and the plugin version [233.15619.7] should have a matching beginning. For example, release version '20201' should match plugin version 2020.1.1 messages (I don't know where cwm-plugin comes from...)

Tested on Arch Linux.

[ingokegel]

For me, 2.2.0/2.2.1 adds ~30 seconds to my Gradle import compared for 2.1.0.

[ForNeVeR]

Gradle Scan results don't give enough insight, so I tried really profiling this.

To me it looks like most of the code is spent in lazy evaluation of IntelliJPlatformDependenciesHelper.getIde, which in turn calls quite deep stacks, all ending up in com.jetbrains.plugin.structure.intellij.plugin.JarFilesResourceResolver — a class living in a separate repo. This one.

Its logic seems quite suboptimal. During IDE load, we issue a lot of requests to various resources from the IDE plugin (my current estimation is at least one request for each plugin per user's Gradle module, and maybe one or two more for tests).

On each resolve of each teeny-tiny product-info.xml or plugin.xml, it creates a whole file system for each of the product plugins (um, O(N²)? I hope I am wrong, please prove me wrong.), and looks for the resource. And after it found the resource, it will leave the underlying ZIP file system open — to be closed later together with the resource.

So, on each lookup it loads through the whole product's plugin set, scans each (at least its zip directory), and closes most of them back — until the next opening.

We cannot cache the open file systems because of how it is supposed to work: each file system will be closed together with its file.

But this looks very suboptimal, perhaps we can introduce an index for this information or something; we don't need to load it again if we know the input IDE didn't change.

[ForNeVeR]

So, I've tried adding a very simple cache: JetBrains/intellij-plugin-verifier#1213

This is very far from being optimal, but already decreases the time for my tests from 2 minutes to 1 minute.

The problem is that we still do a lot of IDE resolve during a build of a multi-module plugin: for Todosaurus' commit 809a588a92d43104c04fb06d4296d270e36f0b8b (3 modules, one of which has tests), for whatever reason, it still fills the same cache for 7 times (!) — meaning different instances of JarFilesResourceResolver get created; probably different instances of IntelliJPlatformDependenciesHelper get created as well. Though I don't understand why is that number 7.

But that probably means we can make it additionally 7x faster, even after the rudimentary optimization! From 1 minute to about
10 seconds. We just need to stop re-resolving the plugins from JARs for so many times.

Additional info the logs show that some modules, e.g. /intellij.docker.backend.split.xml, are resolved for 5145 times during the build. Not a surprise it is a tiny bit slow, eh?

Even after my optimization, this probably means the same XML file is read for 5 thousand times during the build.

We can make it significantly better. There's a vast area for improvement here.

[novotnyr]

I also see this message two times at the configuration stage. I don't know if this is related to the issue.
This is a known issue, quite unrelated to this one. Thanks for pointing this out!

[ForNeVeR]

While I believe the message to be related to the number of times we call the plugin verifier, I am also unsure if it's directly related to the performance issue at hand. Most likely not. IntelliJ has a minor plugin configuration issue of some sort, and the fact that the verifier prints a warning is just another side effect of the fact we call it for so many times during the build and testing.