Investigate mvn4 large graph performance regression

[mbien]

Affected version

4.0.0-rc-3 (resolver 2.0.9)

Bug description

I use this issue to investigate the performance regression posted on the dev list. Github allows to embed pictures which makes sharing flame graphs easier compared to mail.

benchmark project taken from mail thread (thanks to @seregamorph for coming up with a reproducer!):
https://github.com/maven-turbo-reactor/maven-multiproject-generator (https://www.mail-archive.com/dev@maven.apache.org/msg135612.html)

setup (first line are kernel settings for async-profiler):

sudo sysctl kernel.kptr_restrict=0 && sudo sysctl kernel.perf_event_paranoid=1
export JAVA_HOME=/home/mbien/dev/java/jdk-24.0.1.9.1-corretto

mvn3 run:

export MAVEN_OPTS=-agentpath:/home/mbien/dev/java/async-profiler-4.0-linux-x64/lib/libasyncProfiler.so=start,event=cpu,file=maven3.html
/home/mbien/dev/java/apache-maven-9.9.10_40/bin/mvn clean install

mvn4 run:

export MAVEN_OPTS=-agentpath:/home/mbien/dev/java/async-profiler-4.0-linux-x64/lib/libasyncProfiler.so=start,event=cpu,file=maven4.html
/home/mbien/dev/java/apache-maven-4.0.0-rc-3/bin/mvn clean install

(i ran a warmup run first before measuring)

m3
Total time:  01:03 min (Wall Clock)

m4
Total time:  03:08 min (Wall Clock)

(old intel i7 on NVME)

first observation:

mvn3 has 3 paths leading into DefaultRepositorySystem.collectDependencies, mvn4 has 4. The extra path comes from DefaultConsumerPomBuilder, see second observation.

Graphs show relative execution time. No totals.

note: one path is very fast and not visible on this zoom level in both cases, purple marks collectDependencies

mvn3:

mvn4:

second observation:

The reason for that seems to be the install stage. More time is spent in InstallMojo:

m3:

m4:

zooming in shows the difference, the whole RepositoryUtils.toArtifact path is new and is the cause for the extraDefaultRepositorySystem.collectDependencies call.

m3:

m4:

third observation:

more time is spent computing hash codes, purple highlights methods containing "hash".

mvn3:

mvn4:

lets zoom into a single collectDependencies call

mvn3:

mvn4:

full flame graphs as html (compressed since github doesn't like html):

maven3.html.gz
maven4rc3.html.gz

[XenoAmess]

..my profiling show around 15% performance part is from getPluginsAsMap
will try refine it this weekend.

update: #2482

[XenoAmess]

1.2% + 0.7% be in the slow string format function. will refine it also.

update: #2483

[XenoAmess]

log flush: #2478

[XenoAmess]

delete several outdated classes(and their generated copies) #2484

[XenoAmess]

17.32% at the thread start in maven-resolver.
seems there be some thread management problems.
so yes I have to have a look at the maven-resolver repo also(never did this before)

update: apache/maven-resolver#1490
update: apache/maven-resolver#1492