Class Data Sharing を試してみる

Java 10 の Class Data Sharing で　Spring Boot の起動を速くしてみます。

---

Class Data Sharing は異なるJVM上で同一のクラスの情報を共有する仕組みです。 Java 8 の時点ですでに組み込まれていましたが、コマーシャルな機能であったため、 使っている人は少ないと思います。 Java 10 からはこの機能が OpenJDK でも利用できるようになったため、早速試してみたいと思います。

---

Spring　Boot アプリケーション

実行対象とするアプリケーションを作るために次のコマンドでプロジェクトを作ります

gradle init --type=java-library
curl https://start.spring.io/build.gradle \
  -d dependencies=webflux,actuator,data-jpa,thymeleaf,\
validation,data-redis-reactive,flyway,retry,\
statemachine,mail,h2 > build.gradle

次に次のようなメインクラスを作ります。

@SpringBootApplication
public class App {
  public static void main(String... args) {
    SpringApplication.run(App.class, args);
  }

  @Bean
  CommandLineRunner commandLineRunner() {
    return args -> {};
  }

  private final Foo foo;

  App(final Foo foo) {
    this.foo = foo;
  }

  public static class Foo {}
}

JVMの起動時間だけが今は必要なので、SpringのBean読み込みが始まったらすぐに落ちるメインクラスになっています。

---

Spring Boot アプリケーションの起動

Spring Boot アプリケーションを起動したいのですが、 gradle の bootRun タスクに jvm パラメーターを指定する方法でやると、 Class Data のアーカイブディレクトリーがうまく認識されなかったので、 bootJar で作成した jar ファイルを JavaExec タスクで起動します。

task createCdsDirectory {
  outputs.dir(cdsDirectory)
  doLast {
    if (!cdsDirectory.exists()) {
      cdsDirectory.mkdirs()
    }
  }
}

task runBootJar(type: JavaExec) {
  main = 'org.springframework.boot.loader.JarLauncher'
  dependsOn bootJar
  classpath bootJar
  def create = false
  if (project.hasProperty('listApp')) {
    jvmArgs = ['-XX:+UnlockCommercialFeatures', '-Xshare:off', "-XX:DumpLoadedClassList=${classList}", '-XX:+UseAppCDS']
    create = true
  } else if (project.hasProperty('dumpApp')) {
    jvmArgs = ['-XX:+UnlockCommercialFeatures', '-Xshare:dump', "-XX:SharedClassListFile=${classList}", '-XX:+UseAppCDS', "-XX:SharedArchiveFile=${archiveFile}"]
    create = true
  } else if (project.hasProperty('runApp')) {
    jvmArgs = ['-XX:+UnlockCommercialFeatures', '-Xshare:on', '-XX:+UseAppCDS', "-XX:SharedArchiveFile=${archiveFile}"]
  }
  if (create) {
    dependsOn createCdsDirectory, showStartTime
  } else {
    dependsOn showStartTime
  }
  finalizedBy showEndTime
}

Class Data Sharing を使う場合、次の3つのフェーズがあり、それぞれで別のパラメーターを必要とします。

アーカイブ対象リストを取得

• -XX:+UnlockCommercialFeatures
• -XX:+UseAppCDS
• -Xshare:off
• -XX:DumpLoadedClassList=${classList}

アーカイブファイルを取得

• -XX:+UnlockCommercialFeatures
• -XX:+UseAppCDS
• -Xshare:dump
• -XX:SharedClassListFile=${classList}
• -XX:SharedArchiveFile=${archiveFile}

アーカイブファイルを読みこんでアプリケーションを起動する

• -XX:+UnlockCommercialFeatures
• -XX:+UseAppCDS
• -Xshare:on
• -XX:SharedArchiveFile=${archiveFile}

ここでは、 gradle のプロパティ値の有無で起動オプションを変更する形で起動します。

また、実行時間を計測する用途として次の二つのタスクを作ります。

task showStartTime(group: 'show-time') {
  doLast {
    def now = LocalDateTime.now()
    startTime << now
    logger.lifecycle('start {}', now.format(DateTimeFormatter.ISO_LOCAL_DATE_TIME))
  }
}

task showEndTime(group: 'show-time') {
  doLast {
    def now = LocalDateTime.now()
    if (!startTime.empty) {
      LocalDateTime start = startTime[0]
      logger.lifecycle('start {}', start.format(DateTimeFormatter.ISO_LOCAL_DATE_TIME))
      logger.lifecycle('end {}', now.format(DateTimeFormatter.ISO_LOCAL_DATE_TIME))
      def duration = Duration.between(start, now)
      logger.lifecycle('time: {} ms', duration.toMillis())
    }
  }
}

---

Class Data Sharing を使わない場合

Class Data Sharing を使わない場合の起動時間を確認します。

$ ./gradlew clean runBootJar 

> Task :showStartTime 
start 2018-04-01T19:41:48.800745

> Task :runBootJar 

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.0.0.RELEASE)

2018-04-01 19:41:55.441  INFO 8454 --- [           main] com.example.App                          : Starting App on mac.local with PID 8454 (/path/to/project/build/libs/spring-app-cds-sample-0.0.1-SNAPSHOT.jar started by mike in /path/to/project)
2018-04-01 19:41:55.447  INFO 8454 --- [           main] com.example.App                          : No active profile set, falling back to default profiles: default

... 中略

***************************
APPLICATION FAILED TO START
***************************

Description:

Parameter 0 of constructor in com.example.App required a bean of type 'com.example.App$Foo' that could not be found.


Action:

Consider defining a bean of type 'com.example.App$Foo' in your configuration.


> Task :showEndTime 
start 2018-04-01T19:41:48.800745
end 2018-04-01T19:41:59.122787
time: 10322 ms

... 以下省略

JVM起動開始 → クラスロード完了 → Spring Boot アプリケーションの起動 → Spring Boot アプリケーションの終了 の一連の流れで 10322 ms ほどかかりました。

---

Class Data Sharing を使う場合

クラスリストの取得

最初にアーカイブ対象のクラスをリスト化します。

$ ./gradlew runBootJar -PlistApp

> Task :showStartTime 
start 2018-04-01T19:32:34.882318

> Task :runBootJar 
skip writing class com/sun/proxy/$Proxy0 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy1 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy2 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy3 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy9 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/jdk/proxy1/$Proxy11 from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LII from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LIIL from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LIILL from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LIILLL from source __JVM_DefineClass__ to classlist file

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.0.0.RELEASE)

2018-04-01 19:32:41.717  INFO 8413 --- [           main] com.example.App                          : Starting App on mac.local with PID 8413 (/path/to/paroject/build/libs/spring-app-cds-sample-0.0.1-SNAPSHOT.jar started by mike in /path/to/project)
2018-04-01 19:32:41.725  INFO 8413 --- [           main] com.example.App                          : No active profile set, falling back to default profiles: default
skip writing class com/sun/proxy/$Proxy13 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy24 from source __JVM_DefineClass__ to classlist file
2018-04-01 19:32:41.853  INFO 8413 --- [           main] onfigReactiveWebServerApplicationContext : Refreshing org.springframework.boot.web.reactive.context.AnnotationConfigReactiveWebServerApplicationContext@1139b2f3: startup date [Sun Apr 01 19:32:41 JST 2018]; root of context hierarchy
skip writing class java/lang/invoke/BoundMethodHandle$Species_LLLII from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LLLIIL from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LLLIILL from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LLLIILLL from source __JVM_DefineClass__ to classlist file
skip writing class java/lang/invoke/BoundMethodHandle$Species_LLLIILLLL from source __JVM_DefineClass__ to classlist file

... 中略

> Task :showEndTime 
start 2018-04-01T19:32:34.882318
end 2018-04-01T19:32:45.295433
time: 10413 ms

... 以下省略

これによって、次のようなテキストファイルが作成されます。(このサンプルでは build/cds/list.txt が作成される)

$ head -10 build/cds/list.txt 
java/lang/Object
java/lang/String
java/io/Serializable
java/lang/Comparable
java/lang/CharSequence
java/lang/Class
java/lang/reflect/GenericDeclaration
java/lang/reflect/AnnotatedElement
java/lang/reflect/Type
java/lang/Cloneable
$ grep spring build/cds/list.txt  | head -10
org/springframework/boot/loader/JarLauncher
org/springframework/boot/loader/ExecutableArchiveLauncher
org/springframework/boot/loader/Launcher
org/springframework/boot/loader/LaunchedURLClassLoader
org/springframework/boot/loader/archive/Archive
org/springframework/boot/loader/archive/JarFileArchive
org/springframework/boot/loader/jar/JarFile
org/springframework/boot/loader/jar/CentralDirectoryVisitor
org/springframework/boot/loader/data/RandomAccessData
org/springframework/boot/loader/jar/FileHeader

もし、ロードされたくないようなクラスがある場合は、このリストから取り除きます。

リストを取得する処理が入る場合は、ロードされるクラスのスキャンニングが入るため、若干処理が遅くなります。

---

アーカイブファイルの取得

次にアーカイブファイルを取得します。このときの java　コマンドはアプリケーションを起動しません。

$ ./gradlew  runBootJar -PdumpApp

> Task :showStartTime 
start 2018-04-01T20:08:10.186895

> Task :runBootJar 
narrow_klass_base = 0x0000000800000000, narrow_klass_shift = 3
Allocated temporary class space: 1073741824 bytes at 0x00000008c0000000
Allocated shared space: 3221225472 bytes at 0x0000000800000000
Loading classes to share ...
Loading classes to share: done.
Rewriting and linking classes ...
Rewriting and linking classes: done
Number of classes 2131
    instance classes   =  2053
    obj array classes  =    70
    type array classes =     8
Updating ConstMethods ... done. 
Removing unshareable information ... done. 
Scanning all metaspace objects ... 
Allocating RW objects ... 
Allocating RO objects ... 
Relocating embedded pointers ... 
Relocating external roots ... 
Dumping symbol table ...
Dumping String objects to closed archive heap region ...
Dumping objects to open archive heap region ...
Relocating SystemDictionary::_well_known_klasses[] ... 
Removing java_mirror ... done. 
mc  space:      8536 [  0.0% of total] out of     12288 bytes [ 69.5% used] at 0x0000000800000000
rw  space:   5943264 [ 19.0% of total] out of   5943296 bytes [100.0% used] at 0x0000000800003000
ro  space:  11971160 [ 38.4% of total] out of  11972608 bytes [100.0% used] at 0x00000008005ae000
md  space:      6160 [  0.0% of total] out of      8192 bytes [ 75.2% used] at 0x0000000801119000
od  space:  11275744 [ 36.1% of total] out of  11276288 bytes [100.0% used] at 0x000000080111b000
st0 space:    835584 [  2.7% of total] out of    835584 bytes [100.0% used] at 0x00000007bfe00000
st1 space:   1048576 [  3.4% of total] out of   1048576 bytes [100.0% used] at 0x00000007bff00000
oa0 space:    102400 [  0.3% of total] out of    102400 bytes [100.0% used] at 0x00000007bfd00000
total    :  31191424 [100.0% of total] out of  31199232 bytes [100.0% used]

> Task :showEndTime 
start 2018-04-01T20:08:10.186895
end 2018-04-01T20:08:11.906736
time: 1719 ms


BUILD SUCCESSFUL in 4s
6 actionable tasks: 3 executed, 3 up-to-date

これによって、アーカイブファイルが作られます(この例では build/cds/app.jsa)。また、ログの意味を文字通りに解釈するなら、 2131 個のクラスがアーカイブされたようです。実際にファイルを確認してみます。

$ ls -l build/cds/
total 61080
-r--r--r--+ 1 mike  staff  31203328  4  1 20:08 app.jsa
-rw-r--r--+ 1 mike  staff     69515  4  1 19:54 list.txt

---

アーカイブファイルを読み込んでアプリケーションを起動する

では、作成したアーカイブファイルを使って、 Spring Boot アプリケーションを起動してみます。

 $ ./gradlew  runBootJar -PrunApp
Picked up _JAVA_OPTIONS: -Dfile.encoding=UTF-8

> Task :showStartTime 
start 2018-04-01T20:11:56.633207

> Task :runBootJar 

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.0.0.RELEASE)

2018-04-01 20:12:03.401  INFO 8564 --- [           main] com.example.App                          : Starting App on mac.local with PID 8564 (/path/to/project/build/libs/spring-app-cds-sample-0.0.1-SNAPSHOT.jar started by mike in /path/to/project)
2018-04-01 20:12:03.409  INFO 8564 --- [           main] com.example.App                          : No active profile set, falling back to default profiles: default

... 中略

> Task :showEndTime 
start 2018-04-01T20:11:56.633207
end 2018-04-01T20:12:06.830557
time: 10197 ms

... 以下省略

全体の時間は 10197 ms となり、指定しなかったとき(10322 ms)に比べて、 125 ms ほど速くなりました！…あれ、いや、これ誤差ですよね…？？！？！

---

問題と解決

さて、起動時間がほとんど変わらない理由を考えます。先ほどの list.txt をよく見てみます。

org/springframework/boot/loader/JarLauncher
org/springframework/boot/loader/ExecutableArchiveLauncher
org/springframework/boot/loader/Launcher

といったクラスがアーカイブされていますが、これらを見てわかるかもしれませんが、 bootJar によって生成される jar ファイルは一般的な fat jar とは異なり、アプリケーションのクラスがそのまま入っているのではなく、 アプリケーションの jar が中に入っています。確認してみます。

$ unzip -Z1 build/libs/spring-app-cds-sample-0.0.1-SNAPSHOT.jar
org/
org/springframework/
org/springframework/boot/
org/springframework/boot/loader/
org/springframework/boot/loader/data/
org/springframework/boot/loader/util/
org/springframework/boot/loader/archive/
org/springframework/boot/loader/jar/
org/springframework/boot/loader/data/RandomAccessDataFile.class
org/springframework/boot/loader/util/SystemPropertyUtils.class
org/springframework/boot/loader/archive/Archive$EntryFilter.class
org/springframework/boot/loader/archive/ExplodedArchive$FileEntry.class
org/springframework/boot/loader/archive/Archive.class
org/springframework/boot/loader/archive/Archive$Entry.class
org/springframework/boot/loader/Launcher.class

... 中略

BOOT-INF/classes/com/example/App$Foo.class
BOOT-INF/classes/com/example/App.class

... 中略

BOOT-INF/lib/spring-boot-starter-webflux-2.0.0.RELEASE.jar
BOOT-INF/lib/spring-boot-starter-actuator-2.0.0.RELEASE.jar
BOOT-INF/lib/spring-boot-starter-data-jpa-2.0.0.RELEASE.jar
BOOT-INF/lib/spring-boot-starter-thymeleaf-2.0.0.RELEASE.jar
BOOT-INF/lib/spring-boot-starter-validation-2.0.0.RELEASE.jar
BOOT-INF/lib/spring-boot-starter-data-redis-reactive-2.0.0.RELEASE.jar
... 以下省略

つまり、どんなにたくさん依存ライブラリーを使っても bootJar タスクで作成した jar ファイルを Class Data Sharing で起動してもあまり効果がないことがわかります。

そこで、 bootRun のようなラウンチャー経由で起動するわけではない形で Spring Boot アプリケーションを起動したいのですが、前述の通り bootRun に Class Data Sharing のオプションをつけて起動すると、どうしてもアーカイブファイルのパスがうまく認識されません。正確には次のようなコマンドで bootRun は起動されるのですが、アプリケーションのクラスがあるディレクトリーをアーカイブファイルのディレクトリーと認識してしまい、アーカイブファイルを出力してくれません。

java \
  -XX:+UnlockCommercialFeatures \
  -XX:+UseAppCDS \
  -Xshare:dump \
  -XX:SharedClassListFile=classes.txt \
  -XX:SharedArchiveFile=archive.jsa \
  -cp /path/to/project/build/classes/java/main:/path/to/.gradle/foo/bar/spring-foo-bar-1.0.0.jar \
  com.sample.App

したがって、 bootRun とほぼ同様のコマンドで、コンパイルされたアプリケーションをクラスファイルのままではなく、一度 jar に固めて起動するようなタスクを作る必要があります(。もちろん、普通に jar ファイルを作って、それを起動するのでも構いませんが、 jar タスクは Spring Boot plugin によって上書きされているので、あらためて作る必要があります)。

というわけで、そのようなタスクを作り、そのタスク名を cdsBootRun(実装、スクリプトは省略) とします。

---

再確認

では cdsBootRun を使って、起動してみます。

クラスリストの取得

$ ./gradlew cdsBotRun -PlistApp
> Task :showStartTime 
start 2018-04-02T23:00:45.980764

> Task :cdsBootRun 
skip writing class com/sun/proxy/$Proxy0 from source __JVM_DefineClass__ to classlist file
skip writing class com/sun/proxy/$Proxy1 from source __JVM_DefineClass__ to classlist file

... 中略

Action:

Consider defining a bean of type 'com.example.App$Foo' in your configuration.

> Task :showEndTime 
start 2018-04-02T23:00:45.980764
end 2018-04-02T23:00:55.548887
time: 9568 ms

クラスリストを取得するようにJVMパラメーターを調整して実行し、クラスファイルリスト list.txt の中身を確認します。

$ grep spring build/cds/list.txt | head -10
org/springframework/boot/SpringApplication
org/springframework/boot/ApplicationArguments
org/springframework/context/ApplicationContext
org/springframework/core/env/EnvironmentCapable
org/springframework/beans/factory/ListableBeanFactory
org/springframework/beans/factory/BeanFactory
org/springframework/beans/factory/HierarchicalBeanFactory
org/springframework/context/MessageSource
org/springframework/context/ApplicationEventPublisher
org/springframework/core/io/support/ResourcePatternResolver

spring を含むクラスの先頭10行を取得しましたが、先ほどのクラスファイルリストとは異なっていることがわかると思います。これはかなり期待できます！

アーカイブファイルの取得

アーカイブファイルを取得します。

$ ./gradlew cdsBootRun -PdumpApp

> Task :showStartTime 
start 2018-04-02T23:06:08.353299

> Task :cdsBootRun 
narrow_klass_base = 0x0000000800000000, narrow_klass_shift = 3
Allocated temporary class space: 1073741824 bytes at 0x00000008c0000000
Allocated shared space: 3221225472 bytes at 0x0000000800000000
Loading classes to share ...
Preload Warning: Cannot find com/sun/proxy/$Proxy4
Preload Warning: Cannot find org/springframework/core/$Proxy5
Preload Warning: Cannot find org/springframework/core/$Proxy6
Preload Warning: Cannot find com/sun/proxy/$Proxy7
Preload Warning: Cannot find com/sun/proxy/$Proxy8

... 中略

Rewriting and linking classes: done
Number of classes 6389
    instance classes   =  6297
    obj array classes  =    84
    type array classes =     8
Updating ConstMethods ... done. 
Removing unshareable information ... done. 
Scanning all metaspace objects ... 
Allocating RW objects ... 
Allocating RO objects ... 
Relocating embedded pointers ... 
Relocating external roots ... 
Dumping symbol table ...
Dumping String objects to closed archive heap region ...
Dumping objects to open archive heap region ...
Relocating SystemDictionary::_well_known_klasses[] ... 
Removing java_mirror ... done. 
mc  space:      9544 [  0.0% of total] out of     12288 bytes [ 77.7% used] at 0x0000000800000000
rw  space:  15875096 [ 20.8% of total] out of  15876096 bytes [100.0% used] at 0x0000000800003000
ro  space:  29298616 [ 38.4% of total] out of  29298688 bytes [100.0% used] at 0x0000000800f27000
md  space:      6160 [  0.0% of total] out of      8192 bytes [ 75.2% used] at 0x0000000802b18000
od  space:  27230536 [ 35.7% of total] out of  27234304 bytes [100.0% used] at 0x0000000802b1a000
st0 space:    446464 [  0.6% of total] out of    446464 bytes [100.0% used] at 0x00000007bfc00000
st1 space:   3145728 [  4.1% of total] out of   3145728 bytes [100.0% used] at 0x00000007bfd00000
oa0 space:    221184 [  0.3% of total] out of    221184 bytes [100.0% used] at 0x00000007bfb00000
total    :  76233328 [100.0% of total] out of  76242944 bytes [100.0% used]

> Task :showEndTime 
start 2018-04-02T23:06:08.353299
end 2018-04-02T23:06:28.96977
time: 20616 ms


BUILD SUCCESSFUL in 22s
5 actionable tasks: 3 executed, 2 up-to-date

さて、このコマンドの結果にも大きな変更がありました。最初に試したときは 2131 個のファイルがアーカイブされたのに対して、今度は 6389 個のファイルがアーカイブされたようです。

$ ls -l build/cds/
total 149600
-r--r--r--+ 1 mike  staff  76271616  4  2 23:06 app.jsa
-rw-r--r--+ 1 mike  staff    323139  4  2 23:00 list.txt

また、ファイルの大きさを確認しても、最初のときは 31,203,328 だったのに対して、 76,271,616 に増えています。これは本当に期待できそうですよ！

アーカイブファイルを読み込んでアプリケーションを起動する

ではアーカイブファイルを読み込んでアプリケーションを起動してみます。

$ ./gradlew cdsBootRun -PrunApp

> Task :showStartTime 
start 2018-04-02T23:14:33.147381

> Task :cdsBootRun 

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.0.0.RELEASE)

2018-04-02 23:14:39.305  INFO 10455 --- [           main] com.example.App                          : Starting App on mac.local with PID 10455 (/path/to/project/build/customJar/spring-app-cds-sample-0.0.1-SNAPSHOT.jar started by mike in /path/to/project)
2018-04-02 23:14:39.307  INFO 10455 --- [           main] com.example.App                          : No active profile set, falling back to default profiles: default

... 中略

> Task :showEndTime 
start 2018-04-02T23:14:33.147381
end 2018-04-02T23:14:41.733068
time: 8585 ms

... 以下略

結果としては次のようになりました。

• 全体の時間 : 8585 ms

先ほどと比べて…と言いたいところですが、起動するものが変わったので最初にCDSを使わなかったものを比較対象にするのは間違っていますので、あらためてCDSを使わない場合の起動時間を調べてみます。

$ ./gradlew cdsBootRun

> Task :showStartTime 
start 2018-04-02T23:22:34.634671

> Task :cdsBootRun 

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.0.0.RELEASE)

2018-04-02 23:22:40.818  INFO 10507 --- [           main] com.example.App                          : Starting App on mac.local with PID 10507 (/path/to/project/build/customJar/spring-app-cds-sample-0.0.1-SNAPSHOT.jar started by mike in /path/to/project)
2018-04-02 23:22:40.822  INFO 10507 --- [           main] com.example.App                          : No active profile set, falling back to default profiles: default

... 中略

> Task :showEndTime 
start 2018-04-02T23:22:34.634671
end 2018-04-02T23:22:43.906533
time: 9271 ms

... 以下略

CDSを使わなかった場合の起動時間は次のようになりました。

• 全体の時間 : 9271 ms

比較してみると、 CDS を使った場合の方が 686 ms ほど速くなりました！

条件	時間(ms)
CDS使った場合	8585
CDS使わない場合	9271