Maven caplet very slow to launch

[brasslock]

https://groups.google.com/forum/?hl=en-GB#!topic/capsule-user/oqVIPAPzZW4

My system contains a number of different Java applications (approx 20), each of which uses a large number of jar files (> 100 jars). I have been converting the applications from Docker to Capsule in an attempt to reduce the bloat (it takes a long time to transfer multiple large Docker images across a slow network).

Using the fat capsule results in capsule jars of approx 100M each.
Using Maven capsule seemed like the ideal solution to reduce the size, but results in a very slow launch (15 - 30 seconds), even when running in offline mode after having downloaded all jars (-Dcapsule.offline=true).
I have not analysed it in detail, but it seems to be spending a lot of time in the Aether maven dependency management library.

I have configured the capsule dependencies so that all jars are explicitly listed and don't fetch transitive dependencies e.g. org.slf4j:slf4j-api:1.7.12(:)

Ross

[brasslock]

I am currently profiling this in an attempt to get a bit more info to add to this ticket.

[brasslock]

From my profiling Aether is taking very little time.
Instead the majority of time is spent in Capsule#dependencyToLocalJar0.

Capsule profile output:

CAPSULE: PROFILE Load class MavenCapsule 25ms
CAPSULE: PROFILE Load class Capsule 21ms
CAPSULE: PROFILE Read JAR in constructor 5ms
CAPSULE: PROFILE lookupAllDependencies 8334ms
CAPSULE: PROFILE chooseJavaHome 0ms
CAPSULE: PROFILE buildAgents (java) 0ms
CAPSULE: PROFILE buildAgents (native) 0ms
CAPSULE: PROFILE listJar 51ms
CAPSULE: PROFILE buildClassPath 8161ms
CAPSULE: PROFILE buildAppCacheDir 7ms
CAPSULE: PROFILE resolveAll 820ms
CAPSULE: PROFILE listJar 53ms
CAPSULE: PROFILE prepareForLaunch 17418ms
CAPSULE: PROFILE Total 17526ms

Based on profiling:
(lots of call stack left out)

                                 calls
Capsule#prepareForLaunch           [ 1]

 Capsule#lookupAllDependencies     [ 1]
  Capsule#lookupInAttribute        [ 11]
   MavenCapsule#lookup0            [166]
    Capsule#lookup00               [332]
     Capsule#dependencyToLocalJar0 [166]
      ZipInputStream#getNextEntry  [> 200K]

 Capsule#buildClassPath0           [ 1]
  Capsule#lookupInAttribute        [ 1]
   MavenCapsule#lookup0            [166]
    Capsule#lookup00               [332]
     Capsule#dependencyToLocalJar0 [166]
      ZipInputStream#getNextEntry  [> 200K]

It appears as if this code is repeatedly reading and parsing the list of entries in the main jar file.

I assume it would be relatively easy to cache that info about the jar file, and then simply use that info each time.

Ross

[pron]

Good job! This is something we can work with. Thanks!

[pron]

Hi. I've added caching. Could you test now against master or 1.0.2-SNAPSHOT on sonatype?

[brasslock]

Fixed the launch time issue for me, thanks!

CAPSULE: PROFILE Load class MavenCapsule 27ms
CAPSULE: PROFILE Load class Capsule 22ms
CAPSULE: PROFILE Read JAR in constructor 4ms
CAPSULE: PROFILE lookupAllDependencies 131ms
CAPSULE: PROFILE chooseJavaHome 0ms
CAPSULE: PROFILE buildAgents (java) 0ms
CAPSULE: PROFILE buildAgents (native) 0ms
CAPSULE: PROFILE listJar 57ms
CAPSULE: PROFILE buildClassPath 88ms
CAPSULE: PROFILE buildAppCacheDir 7ms
CAPSULE: PROFILE resolveAll 814ms
CAPSULE: PROFILE listJar 54ms
CAPSULE: PROFILE prepareForLaunch 1130ms
CAPSULE: PROFILE Total 1232ms

Reduced the launch time from > 17 seconds, to about 1.2 seconds for my test application.

Thanks.

[pron]

You did all the hard work.