Re: Speeding up Maven

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Re: Speeding up Maven

Mark Raynsford
On 2018-04-13T21:48:58 +0200
Karl Heinz Marbaise <[hidden email]> wrote:

> Hi Mark,

'Ello.

> On 13/04/18 21:20, Mark Raynsford wrote:
>
> First it would be good to know which Maven version are you using? And on
> which JDK you are running?

Hah, I purposefully left out details in the hope that it wouldn't be my
problem specifically. From the one second build you've described, it
appears that perhaps it might be.

My system:

Linux copperhead.int.arc7.info 4.15.14-1-ARCH #1 SMP PREEMPT Wed Mar 28
17:34:29 UTC 2018 x86_64 GNU/Linux

Intel(R) Core(TM) i5-2410M CPU @ 2.30GHz, 8GB ram.

openjdk version "9.0.4"
OpenJDK Runtime Environment (build 9.0.4+11)
OpenJDK 64-Bit Server VM (build 9.0.4+11, mixed mode)

Apache Maven 3.5.2 (NON-CANONICAL_2017-10-25T13:09:52+03:00_root;
2017-10-25T10:09:52Z) Maven home: /opt/maven
Java version: 9.0.4, vendor: Oracle Corporation
Java home: /usr/lib/jvm/java-9-openjdk
Default locale: en_GB, platform encoding: UTF-8
OS name: "linux", version: "4.15.14-1-arch", arch: "amd64", family:
"unix"

> Maybe I misunderstand you ...are you running it from plain command line
> or from inside your IDE ?

The command line in the log is:

  mvn -Dmaven.tests.skip=true -DskipTests=true package

Although in the IDE in real projects, I'm skipping more plugin
executions than that.

>
> What are you memory settings? How is your JDK configured ? Which command
> line options ? (MAVEN_OPTS?):??

I'm both running it from the command line and from the IDE. My point
was that 16 seconds for a command line build is tolerable (although
still pretty damn high for a project that only compiles one Java file
and doesn't do anything else), but running the same build from within
an IDE is painful (because in the IDE, I'm hoping for instant gratification
when I click "Run..." and I don't care about producing a full build
that someone else will use).

$ env | grep MAVEN
MAVEN_OPTS=-Xmx512m

My JDK is essentially unconfigured. Whatever the default settings are
for Linux AMD64, OpenJDK 9.

> Depending on your JVM and the configuration that can be quite large
> different time on startup...there are several configurations which can
> be used to improve that...

I'm open to suggestions. I'm fairly confident that it's not JVM startup
time that's the issue. For example, if I add the -X flag to Maven, you
can see that control reaches whatever passes for Maven's main() function
in roughly one second:

2018-04-13 21:00:01.455570500
2018-04-13 21:00:02.740905500 Apache Maven 3.5.2 (NON-CANONICAL_2017-10-25T13:09:52+03:00_root; 2017-10-25T10:09:52Z)
2018-04-13 21:00:02.741034500 Maven home: /opt/maven
2018-04-13 21:00:02.741192500 Java version: 9.0.4, vendor: Oracle Corporation
2018-04-13 21:00:02.741333500 Java home: /usr/lib/jvm/java-9-openjdk
2018-04-13 21:00:02.741454500 Default locale: en_GB, platform encoding: UTF-8
2018-04-13 21:00:02.741829500 OS name: "linux", version: "4.15.14-1-arch", arch: "amd64", family: "unix"
2018-04-13 21:00:06.841656500 [DEBUG] Created new class realm maven.api
2018-04-13 21:00:06.842724500 [DEBUG] Importing foreign packages into class realm maven.api
2018-04-13 21:00:06.844680500 [DEBUG]   Imported: javax.annotation.* < plexus.core
2018-04-13 21:00:06.847413500 [DEBUG]   Imported: javax.enterprise.inject.* < plexus.core
2018-04-13 21:00:06.847911500 [DEBUG]   Imported: javax.enterprise.util.* < plexus.core
2018-04-13 21:00:06.848473500 [DEBUG]   Imported: javax.inject.* < plexus.core
2018-04-13 21:00:06.849076500 [DEBUG]   Imported: org.apache.maven.* < plexus.core
2018-04-13 21:00:06.849575500 [DEBUG]   Imported: org.apache.maven.artifact < plexus.core
2018-04-13 21:00:06.850103500 [DEBUG]   Imported: org.apache.maven.classrealm < plexus.core
2018-04-13 21:00:06.850619500 [DEBUG]   Imported: org.apache.maven.cli < plexus.core
2018-04-13 21:00:06.851178500 [DEBUG]   Imported: org.apache.maven.configuration < plexus.core
2018-04-13 21:00:06.851678500 [DEBUG]   Imported: org.apache.maven.exception < plexus.core
2018-04-13 21:00:06.852183500 [DEBUG]   Imported: org.apache.maven.execution < plexus.core
2018-04-13 21:00:06.852685500 [DEBUG]   Imported: org.apache.maven.execution.scope < plexus.core
2018-04-13 21:00:06.853183500 [DEBUG]   Imported: org.apache.maven.lifecycle < plexus.core
2018-04-13 21:00:06.853653500 [DEBUG]   Imported: org.apache.maven.model < plexus.core
2018-04-13 21:00:06.854292500 [DEBUG]   Imported: org.apache.maven.monitor < plexus.core
2018-04-13 21:00:06.854777500 [DEBUG]   Imported: org.apache.maven.plugin < plexus.core
2018-04-13 21:00:06.855287500 [DEBUG]   Imported: org.apache.maven.profiles < plexus.core
2018-04-13 21:00:06.855786500 [DEBUG]   Imported: org.apache.maven.project < plexus.core
2018-04-13 21:00:06.856284500 [DEBUG]   Imported: org.apache.maven.reporting < plexus.core
2018-04-13 21:00:06.856757500 [DEBUG]   Imported: org.apache.maven.repository < plexus.core
2018-04-13 21:00:06.857291500 [DEBUG]   Imported: org.apache.maven.rtinfo < plexus.core
2018-04-13 21:00:06.857751500 [DEBUG]   Imported: org.apache.maven.settings < plexus.core
2018-04-13 21:00:06.858242500 [DEBUG]   Imported: org.apache.maven.toolchain < plexus.core
2018-04-13 21:00:06.858750500 [DEBUG]   Imported: org.apache.maven.usability < plexus.core
2018-04-13 21:00:06.859247500 [DEBUG]   Imported: org.apache.maven.wagon.* < plexus.core
2018-04-13 21:00:06.859817500 [DEBUG]   Imported: org.apache.maven.wagon.authentication < plexus.core
2018-04-13 21:00:06.860359500 [DEBUG]   Imported: org.apache.maven.wagon.authorization < plexus.core
2018-04-13 21:00:06.860882500 [DEBUG]   Imported: org.apache.maven.wagon.events < plexus.core
2018-04-13 21:00:06.861413500 [DEBUG]   Imported: org.apache.maven.wagon.observers < plexus.core
2018-04-13 21:00:06.861943500 [DEBUG]   Imported: org.apache.maven.wagon.proxy < plexus.core
2018-04-13 21:00:06.862494500 [DEBUG]   Imported: org.apache.maven.wagon.repository < plexus.core
2018-04-13 21:00:06.862991500 [DEBUG]   Imported: org.apache.maven.wagon.resource < plexus.core
2018-04-13 21:00:06.863587500 [DEBUG]   Imported: org.codehaus.classworlds < plexus.core
2018-04-13 21:00:06.864084500 [DEBUG]   Imported: org.codehaus.plexus.* < plexus.core
2018-04-13 21:00:06.864589500 [DEBUG]   Imported: org.codehaus.plexus.classworlds < plexus.core
2018-04-13 21:00:06.865246500 [DEBUG]   Imported: org.codehaus.plexus.component < plexus.core
2018-04-13 21:00:06.865785500 [DEBUG]   Imported: org.codehaus.plexus.configuration < plexus.core
2018-04-13 21:00:06.866347500 [DEBUG]   Imported: org.codehaus.plexus.container < plexus.core
2018-04-13 21:00:06.866863500 [DEBUG]   Imported: org.codehaus.plexus.context < plexus.core
2018-04-13 21:00:06.867389500 [DEBUG]   Imported: org.codehaus.plexus.lifecycle < plexus.core
2018-04-13 21:00:06.867877500 [DEBUG]   Imported: org.codehaus.plexus.logging < plexus.core
2018-04-13 21:00:06.868428500 [DEBUG]   Imported: org.codehaus.plexus.personality < plexus.core
2018-04-13 21:00:06.868969500 [DEBUG]   Imported: org.codehaus.plexus.util.xml.Xpp3Dom < plexus.core
2018-04-13 21:00:06.869528500 [DEBUG]   Imported: org.codehaus.plexus.util.xml.pull.XmlPullParser < plexus.core
2018-04-13 21:00:06.870156500 [DEBUG]   Imported: org.codehaus.plexus.util.xml.pull.XmlPullParserException < plexus.core
2018-04-13 21:00:06.870915500 [DEBUG]   Imported: org.codehaus.plexus.util.xml.pull.XmlSerializer < plexus.core
2018-04-13 21:00:06.871710500 [DEBUG]   Imported: org.eclipse.aether.* < plexus.core
2018-04-13 21:00:06.872369500 [DEBUG]   Imported: org.eclipse.aether.artifact < plexus.core
2018-04-13 21:00:06.872882500 [DEBUG]   Imported: org.eclipse.aether.collection < plexus.core
2018-04-13 21:00:06.873802500 [DEBUG]   Imported: org.eclipse.aether.deployment < plexus.core
2018-04-13 21:00:06.874304500 [DEBUG]   Imported: org.eclipse.aether.graph < plexus.core
2018-04-13 21:00:06.874690500 [DEBUG]   Imported: org.eclipse.aether.impl < plexus.core
2018-04-13 21:00:06.875170500 [DEBUG]   Imported: org.eclipse.aether.installation < plexus.core
2018-04-13 21:00:06.875679500 [DEBUG]   Imported: org.eclipse.aether.internal.impl < plexus.core
2018-04-13 21:00:06.876191500 [DEBUG]   Imported: org.eclipse.aether.metadata < plexus.core
2018-04-13 21:00:06.876668500 [DEBUG]   Imported: org.eclipse.aether.repository < plexus.core
2018-04-13 21:00:06.877151500 [DEBUG]   Imported: org.eclipse.aether.resolution < plexus.core
2018-04-13 21:00:06.877530500 [DEBUG]   Imported: org.eclipse.aether.spi < plexus.core
2018-04-13 21:00:06.877950500 [DEBUG]   Imported: org.eclipse.aether.transfer < plexus.core
2018-04-13 21:00:06.878354500 [DEBUG]   Imported: org.eclipse.aether.version < plexus.core
2018-04-13 21:00:06.878870500 [DEBUG]   Imported: org.fusesource.jansi.* < plexus.core
2018-04-13 21:00:06.879322500 [DEBUG]   Imported: org.slf4j.* < plexus.core
2018-04-13 21:00:06.879766500 [DEBUG]   Imported: org.slf4j.helpers.* < plexus.core
2018-04-13 21:00:06.880195500 [DEBUG]   Imported: org.slf4j.spi.* < plexus.core
2018-04-13 21:00:06.880859500 [DEBUG] Populating class realm maven.api
2018-04-13 21:00:07.210344500 [INFO] Error stacktraces are turned on.
2018-04-13 21:00:07.210806500 [DEBUG] Message scheme: color
2018-04-13 21:00:07.214240500 [DEBUG] Message styles: debug info warning error success failure strong mojo project
2018-04-13 21:00:07.236587500 [DEBUG] Reading global settings from /opt/maven/conf/settings.xml
2018-04-13 21:00:07.237263500 [DEBUG] Reading user settings from /home/someone/.m2/settings.xml
2018-04-13 21:00:07.343776500 [DEBUG] Reading global toolchains from /opt/maven/conf/toolchains.xml
2018-04-13 21:00:07.344127500 [DEBUG] Reading user toolchains from /home/someone/.m2/toolchains.xml
2018-04-13 21:00:07.381532500 [DEBUG] Using local repository at /home/someone/.m2/repository
2018-04-13 21:00:07.482942500 [DEBUG] Using manager EnhancedLocalRepositoryManager with priority 10.0 for /home/someone/.m2/repository
2018-04-13 21:00:07.528131500 [INFO] Scanning for projects...

You can see that it takes roughly a second to get as far as
printing the "Apache Maven 3.5.2..." message, and then takes
about four seconds to get to "Created new class realm...".
It's up to seven seconds before it even starts scanning for
projects. The build then takes a good 5-7 seconds on top of
that. That equates to about twelve seconds minimum when I
click "Run..." in an IDE, for a single-module build with
next to no plugins executing.

Are there options that can improve Maven's startup time?

The maven-buildtime-profiler plugin will definitely be useful
for larger builds, but right now I'm concerned about this
bit of overhead that appears to be present for even the most
trivial of builds. I'm not sure the profiler will even see that
overhead as it happens before the profiler would have a chance
to capture data.

--
Mark Raynsford | http://www.io7m.com


attachment0 (235 bytes) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Speeding up Maven

Mark Raynsford
With absolutely impeccable timing, I've had a couple of hardware
failures. It is theoretically possible that this was the cause of the
performance issues - although there were no error messages logged
anywhere.

I'm waiting for replacement parts, so it'll be a week or so before I
can continue pulling on this thread.

Thanks for the responses, all!

--
Mark Raynsford | http://www.io7m.com


attachment0 (235 bytes) Download Attachment