[
https://issues.apache.org/jira/browse/MNG-7677?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Tamas Cservenak closed MNG-7677.
--------------------------------
Resolution: Fixed
> Maven 3.9.0 is ~10% slower than 3.8.7 in large multi-module builds
> ------------------------------------------------------------------
>
> Key: MNG-7677
> URL: https://issues.apache.org/jira/browse/MNG-7677
> Project: Maven
> Issue Type: Bug
> Components: Performance
> Affects Versions: 3.9.0
> Reporter: Petr Široký
> Assignee: Tamas Cservenak
> Priority: Minor
> Fix For: 3.9.1
>
> Attachments: profile-alloc-mvn-validate-3.8.7.html,
> profile-alloc-mvn-validate-3.9.0.html, profile-cpu-mvn-validate-3.8.7.html,
> profile-cpu-mvn-validate-3.9.0.html,
> profile-method-DefaultArtifact._init_-3.8.7.html,
> profile-method-DefaultArtifact._init_-3.9.0.html,
> profile-method-DefaultArtifact._init_-3.9.1-SNAPSHOT-reverted-PR166.html
>
>
> When testing the upcoming [Maven release
> 3.9.0|https://repository.apache.org/content/repositories/maven-1862/org/apache/maven/apache-maven/3.9.0/apache-maven-3.9.0-bin.tar.gz]
> I noticed the builds for large multi-module projects are somewhat slower.
> I was mainly using the [Quarkus
> projects|https://github.com/quarkusio/quarkus], which has more than 1k
> modules. I was specifically bulding the {{2.16.1.Final}} tag. Below are the
> numbers I got.
> *First batch:*
> {code:java}
> MAVEN_OPTS="-XX:+UseParallelGC -Xms2g -Xmx2g"{code}
> ||Maven cmd||Build time - Maven 3.8.7||Build time - Maven 3.9.0||
> |clean|2.9s|3.2s|
> |validate|02:17min|02:34min|
> |validate -T8|29s|33s|
> |validate -Dversion.enforcer.plugin=3.2.1|29s|40s|
> |validate -Dversion.enforcer.plugin=3.2.1 -T8|9s|14s|
> *Second batch (bigger heap):*
> {code:java}
> MAVEN_OPTS="-XX:+UseParallelGC -Xms5g -Xmx5g"{code}
> ||Maven cmd||Build time - Maven 3.8.7||Build time - Maven 3.9.0||
> |clean|2.9s|3.2s|
> |validate|02:11min|02:22min|
> |validate -T8|25s|28s|
> |validate -Dversion.enforcer.plugin=3.2.1|29s|35s|
> |validate -Dversion.enforcer.plugin=3.2.1 -T8|9s|11s|
> |install -DskipTests -Dversion.enforcer.plugin=3.2.1 -T8|01:49min|01:55min|
> *Notes:*
> * The numbers are taken from the Maven output (the Wall Clock time). When
> testing with the time utility, the "real" execution time is about 0.6s longer
> (the time JVM needs to start-up). The values in the tables are averages over
> several runs (3 to 10 depending on the time the specific run actually took).
> * All builds were run on Linux x64 (kernel 6.1.8) with JDK 19.0.1
> * HW used during testing: AMD Ryzen 5800x (8 physical cores), 32GB RAM and
> SSD Samsung 980 Pro 1TB (these should not really matter for the comparison
> itself, but I am including it for completeness)
> * Using {{ParallelGC}} since it should be the one with highest throughput
> (at the cost of longer pause times, which I don't really care about for Maven
> builds). Quick comparison with {{G1GC}} shows the builds are slightly faster,
> but it is almost negligible.
> There has already been some discussion regarding this in this older merged PR
> [https://github.com/apache/maven-resolver/pull/166] (which may be the cause
> behind the slowdown).
> See the attachments for CPU / allocation profiles (flame graphs), running
> {{mvn validate}} with both 3.8.7 and 3.9.0.
> *My analysis of the attached CPU / allocation profiles:*
> I was mainly looking at the differences in those two profiles (3.8.7 vs
> 3.9.0), not at the absolute numbers. There are possibly other places that
> could use some optimization, but that is outside of scope for this one.
> Both CPU and allocation profiles show that the CPU time / allocations
> increased the most in a code which seems to be doing some sort of dependency
> resolution, ultimately boiling down to a call to
> {{{}org.eclipse.aether.internal.impl.DefaultRepositorySystem.collectDependencies{}}}.
> The flame graphs show a bit different method calls inside Aether
> (maven-resolver), mainly because there are some structural changes (e.g.
> different class names) to the Aether dependency resolution between
> {{maven-resolver-1.6.3}} (used in {{{}3.8.7{}}}) and {{maven-resolver-1.9.4}}
> (used in {{{}3.9.0{}}}). The dependency resolution algorithm should be the
> same though (or at least as far as I can tell).
> Digging further down, the biggest difference seems to be in the number of
> calls to {{{}org.eclipse.aether.artifact.DefaultArtifact.<init>{}}}. The
> constructor includes merging two property maps together, which results in
> quite some work (CPU) and lots of garbage (HashMap$Node, etc).
> With the above assumption, I went on to profile the number of method
> (constructor) calls to {{org.eclipse.aether.artifact.DefaultArtifact.<init>}}
> (see the attachments
> profile-method-DefaultArtifact._init_-(3.8.7|3.9.0).html). The absolute
> numbers say that Maven 3.8.7 allocated ~9mil of these objects, while Maven
> 3.9.0 allocated ~26mil instances. That is about 3x times as much. When
> drilling down to the method
> {{org.eclipse.aether.internal.impl.DefaultRepositorySystem.collectDependencies}}
> and summing all the instances (there are three), we get ~2mil for instances
> for Maven 3.8.7 and ~19mil instances for Maven 3.9.0. Even if this would not
> be the root cause the "slowness" I am seeing, it is definitely something to
> look at.
> After some further digging in the -Aether- maven-resolver code I found the
> already mentioned change done in PR
> [https://github.com/apache/maven-resolver/pull/166]. It basically replaces
> strong reference to {{org.eclipse.aether.artifact.DefaultArtifact.<init>}}
> with a weak reference, which likely means the instances are cleaned-up much
> faster, and next time they are needed they must be constructed from scratch
> again. The change basically trades lower memory consumption for higher CPU
> usage (and more garbage).
> I then tried to revert the change in
> https://github.com/apache/maven-resolver/pull/166, build maven-resolver
> 1.9.5-SNAPSHOT, update the resolver in maven-3.9.x branch and build from
> that. With this change reverted, I am basically seeing the same numbers as
> with Maven 3.8.7. Running the method profiling for
> {{org.eclipse.aether.artifact.DefaultArtifact.<init>}} with the updated Maven
> also shows the number of instances is back ~9mil as with Maven 3.8.7. Thus,
> at this point, I believe the change in
> https://github.com/apache/maven-resolver/pull/166 is the root behind the
> "slowness". If the change itself should remain, then we should probably take
> another look at how to better cache the instances.
>
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
