Spring Native（ベータ版）が公開されたので実験してみた
- 目標
- 環境
- [OK] Getting Startedで動作を確認
- [NG] samplesの何かで動作を確認
- [OK] samplesの何かで動作を確認
- [OK] Spring Initializrでプロジェクトを作って動作を確認
- 参考リンク
目標
- Getting Startedで動作を確認
- samplesの何かで動作を確認
- Spring Initializrでプロジェクトを作って動作を確認
環境
- Debian 10.8 (WSL2)
- Docker Comunity Edition (Client=19.03.11, Server=20.10.5)
- GraalVM CE 21.0.0.2 (build 11.0.10+8-jvmci-21.0-b06)
- Apache Maven 3.6.3
[OK] Getting Startedで動作を確認
gs-rest-serviceを使う。
spring-boot-starter-webだけのサンプルプロジェクトで、native-imageのためのヒントとかリソースとかは何も含まない状態。
pom.xmlにSpring Nativeの記述を追加してビルドしてみた。
途中で警告メッセージ(Could not register reflection metadata for ...)は出るけど成功してる。
$ git clone https://github.com/spring-guides/gs-rest-service $ cd gs-rest-service/complete $ mvn spring-boot:build-image <snip> <snip> <snip> [INFO] --- spring-boot-maven-plugin:2.4.3:build-image (default-cli) @ rest-service --- [INFO] Building image 'com.example/rest-service:0.0.1-SNAPSHOT' [INFO] [INFO] > Pulling builder image 'docker.io/paketobuildpacks/builder:tiny' 100% [INFO] > Pulled builder image 'paketobuildpacks/builder@sha256:870c2769a65f29c62a0ffe397ae14cc1d61c2e90ebe85f068e8e2fff775c0344' [INFO] > Pulling run image 'docker.io/paketobuildpacks/run:tiny-cnb' 100% [INFO] > Pulled run image 'paketobuildpacks/run@sha256:30e7b4b0e1de31e763c7b631161a508c0ef710ea44924f65177afad2644312b9' [INFO] > Executing lifecycle version v0.10.2 [INFO] > Using build cache volume 'pack-cache-64d3936a0bf9.build' [INFO] [INFO] > Running creator [INFO] [creator] ===> DETECTING [INFO] [creator] 4 of 11 buildpacks participating [INFO] [creator] paketo-buildpacks/graalvm 6.0.0 [INFO] [creator] paketo-buildpacks/executable-jar 5.0.0 [INFO] [creator] paketo-buildpacks/spring-boot 4.1.0 [INFO] [creator] paketo-buildpacks/native-image 4.0.0 [INFO] [creator] ===> ANALYZING [INFO] [creator] Previous image with name "com.example/rest-service:0.0.1-SNAPSHOT" not found [INFO] [creator] ===> RESTORING [INFO] [creator] ===> BUILDING [INFO] [creator] [INFO] [creator] Paketo GraalVM Buildpack 6.0.0 [INFO] [creator] https://github.com/paketo-buildpacks/graalvm [INFO] [creator] Build Configuration: [INFO] [creator] $BP_JVM_VERSION 8.* the Java version [INFO] [creator] Launch Configuration: [INFO] [creator] $BPL_JVM_HEAD_ROOM 0 the headroom in memory calculation [INFO] [creator] $BPL_JVM_LOADED_CLASS_COUNT 35% of classes the number of loaded classes in memory calculation [INFO] [creator] $BPL_JVM_THREAD_COUNT 250 the number of threads in memory calculation [INFO] [creator] $JAVA_TOOL_OPTIONS the JVM launch flags [INFO] [creator] GraalVM JDK 8.0.282: Contributing to layer [INFO] [creator] Downloading from https://github.com/graalvm/graalvm-ce-builds/releases/download/vm-21.0.0.2/graalvm-ce-java8-linux-amd64-21.0.0.2.tar.gz [INFO] [creator] Verifying checksum [INFO] [creator] Expanding to /layers/paketo-buildpacks_graalvm/jdk [INFO] [creator] Adding 129 container CA certificates to JVM truststore [INFO] [creator] GraalVM Native Image Substrate VM 8.0.282 [INFO] [creator] Downloading from https://github.com/graalvm/graalvm-ce-builds/releases/download/vm-21.0.0.2/native-image-installable-svm-java8-linux-amd64-21.0.0.2.jar [INFO] [creator] Verifying checksum [INFO] [creator] Installing substrate VM [INFO] [creator] Processing Component archive: /tmp/e2a182c1f79d8a97b537b843eb65e15ef5ebdd088ad01acd606bf26b1846612e/native-image-installable-svm-java8-linux-amd64-21.0.0.2.jar [INFO] [creator] Installing new component: Native Image (org.graalvm.native-image, version 21.0.0.2) [INFO] [creator] Writing env.build/JAVA_HOME.override [INFO] [creator] Writing env.build/JDK_HOME.override [INFO] [creator] [INFO] [creator] Paketo Executable JAR Buildpack 5.0.0 [INFO] [creator] https://github.com/paketo-buildpacks/executable-jar [INFO] [creator] Class Path: Contributing to layer [INFO] [creator] Writing env.build/CLASSPATH.delim [INFO] [creator] Writing env.build/CLASSPATH.prepend [INFO] [creator] [INFO] [creator] Paketo Spring Boot Buildpack 4.1.0 [INFO] [creator] https://github.com/paketo-buildpacks/spring-boot [INFO] [creator] Class Path: Contributing to layer [INFO] [creator] Writing env.build/CLASSPATH.append [INFO] [creator] Writing env.build/CLASSPATH.delim [INFO] [creator] Image labels: [INFO] [creator] org.opencontainers.image.title [INFO] [creator] org.opencontainers.image.version [INFO] [creator] org.springframework.boot.spring-configuration-metadata.json [INFO] [creator] org.springframework.boot.version [INFO] [creator] [INFO] [creator] Paketo Native Image Buildpack 4.0.0 [INFO] [creator] https://github.com/paketo-buildpacks/native-image [INFO] [creator] Build Configuration: [INFO] [creator] $BP_NATIVE_IMAGE true enable native image build [INFO] [creator] $BP_NATIVE_IMAGE_BUILD_ARGUMENTS arguments to pass to the native-image command [INFO] [creator] Native Image: Contributing to layer [INFO] [creator] GraalVM Version 21.0.0.2 (Java Version 1.8.0_282-b07) [INFO] [creator] Executing native-image -H:+StaticExecutableWithDynamicLibC -H:Name=/layers/paketo-buildpacks_native-image/native-image/com.example.restservice.RestServiceApplication <snip> <snip> <snip> [INFO] [creator] ===> EXPORTING [INFO] [creator] Adding 1/1 app layer(s) [INFO] [creator] Adding layer 'launcher' [INFO] [creator] Adding layer 'config' [INFO] [creator] Adding layer 'process-types' [INFO] [creator] Adding label 'io.buildpacks.lifecycle.metadata' [INFO] [creator] Adding label 'io.buildpacks.build.metadata' [INFO] [creator] Adding label 'io.buildpacks.project.metadata' [INFO] [creator] Adding label 'org.opencontainers.image.title' [INFO] [creator] Adding label 'org.opencontainers.image.version' [INFO] [creator] Adding label 'org.springframework.boot.spring-configuration-metadata.json' [INFO] [creator] Adding label 'org.springframework.boot.version' [INFO] [creator] Setting default process type 'web' [INFO] [creator] *** Images (dfa282b4df5d): [INFO] [creator] com.example/rest-service:0.0.1-SNAPSHOT [INFO] [creator] Adding cache layer 'paketo-buildpacks/graalvm:jdk' [INFO] [creator] Adding cache layer 'paketo-buildpacks/native-image:native-image' [INFO] [INFO] Successfully built image 'com.example/rest-service:0.0.1-SNAPSHOT'
作成したイメージはわりと小さい（75.3MB）。
$ docker images | grep com.example/rest-service
com.example/rest-service 0.0.1-SNAPSHOT dfa282b4df5d 41 years ago 75.3MB
$ dive --ci com.example/rest-service:0.0.1-SNAPSHOT
Using default CI config
Image Source: docker://com.example/rest-service:0.0.1-SNAPSHOT
Fetching image... (this can take a while for large images)
Analyzing image...
efficiency: 99.9996 %
wastedBytes: 481 bytes (481 B)
userWastedPercent: 0.0008 %
Inefficient Files:
Count Wasted Space File Path
2 342 B /etc/passwd
2 139 B /etc/group
Results:
PASS: highestUserWastedPercent
SKIP: highestWastedBytes: rule disabled
PASS: lowestEfficiency
Result:PASS [Total:3] [Passed:2] [Failed:0] [Warn:0] [Skipped:1]
当然ながら起動時間は超短い。
Started RestServiceApplication in 0.065 seconds (JVM running for 0.067)ってすごいなぁ。
普通にJVMで実行すると10秒かかるので100倍以上高速化することになる。
リクエストを受け付けるたびにdispatcherServletを初期化してるのはなんでだろう :thinking_face:
$ curl -s localhost:8080/greeting
{"id":1,"content":"Hello, World!"}
$ curl -s localhost:8080/greeting
{"id":2,"content":"Hello, World!"}
---
$ docker run --rm -i -p 8080:8080 com.example/rest-service:0.0.1-SNAPSHOT
2021-03-12 01:29:33.773 INFO 1 --- [ main] o.s.nativex.NativeListener : This application is bootstrapped with code generated with Spring AOT
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.4.3)
2021-03-12 01:29:33.774 INFO 1 --- [ main] c.e.restservice.RestServiceApplication : Starting RestServiceApplication using Java 1.8.0_282 on b573482d1411 with PID 1 (/workspace/com.example.restservice.RestServiceApplication started by cnb in /workspace)
2021-03-12 01:29:33.774 INFO 1 --- [ main] c.e.restservice.RestServiceApplication : No active profile set, falling back to default profiles: default
2021-03-12 01:29:33.805 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
Mar 12, 2021 1:29:33 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-8080"]
Mar 12, 2021 1:29:33 AM org.apache.catalina.core.StandardService startInternal
INFO: Starting service [Tomcat]
Mar 12, 2021 1:29:33 AM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet engine: [Apache Tomcat/9.0.43]
Mar 12, 2021 1:29:33 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring embedded WebApplicationContext
2021-03-12 01:29:33.807 INFO 1 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 32 ms
2021-03-12 01:29:33.816 INFO 1 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'
Mar 12, 2021 1:29:33 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-nio-8080"]
2021-03-12 01:29:33.824 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2021-03-12 01:29:33.825 INFO 1 --- [ main] c.e.restservice.RestServiceApplication : Started RestServiceApplication in 0.065 seconds (JVM running for 0.067)
Mar 12, 2021 1:31:09 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-03-12 01:31:09.977 INFO 1 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-03-12 01:31:09.977 INFO 1 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms
Mar 12, 2021 1:31:09 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-03-12 01:31:09.977 INFO 1 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-03-12 01:31:09.977 INFO 1 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms
[NG] samplesの何かで動作を確認
samples/data-jpaで実験。
$ git clone https://github.com/spring-projects-experimental/spring-native $ cd spring-native/samples/data-jpa
build-imageは途中まで順調だけど失敗する。
$ mvn spring-boot:build-image <snip> <snip> <snip> [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.data.querydsl.binding.QuerydslBindingsFactory. Reason: java.lang.NoClassDefFoundError: com/querydsl/core/types/EntityPath. [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.transaction.ReactiveTransactionManager. Reason: java.lang.NoClassDefFoundError: reactor/core/publisher/Mono. [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.boot.autoconfigure.transaction.jta.BitronixJtaConfiguration. Reason: java.lang.NoClassDefFoundError: bitronix/tm/Configuration. [INFO] [creator] 01:00:52.940 [ForkJoinPool-2-worker-1] DEBUG org.jboss.logging - Logging Provider: org.jboss.logging.Log4j2LoggerProvider [INFO] [creator] Error: Image build request failed with exit status 137 [INFO] [creator] unable to invoke layer creator [INFO] [creator] unable to contribute native-image layer [INFO] [creator] error running build [INFO] [creator] exit status 137 [INFO] [creator] ERROR: failed to build: exit status 1 [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------
exit statusの説明はnative-imageのリファレンスに書いてない。
QuarkusのOpen Issue#1140のコメントによるとOOMkillerによる異常終了だそうな。
native-imageから実行するjavaのヒープサイズを大きくとるようにすれば解決するかもしれないらしい。
Building a native image with graalvm ce rc11 & rc12, I occasionally see the following error;
Error: Image building with exit status 137
This occurs if the system runs out of ram (including free swap pages) and the OOM Killer terminates the native image build process. The error message seen by users is not very informative. Could we capture the exit code of the native-image process, and if equal to 137, display a more helpful message to users?
$ mvn spring-boot:build-image <snip> <snip> <snip> [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.data.querydsl.binding.QuerydslBindingsFactory. Reason: java.lang.NoClassDefFoundError: com/querydsl/core/types/EntityPath. [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.transaction.ReactiveTransactionManager. Reason: java.lang.NoClassDefFoundError: reactor/core/publisher/Mono. [INFO] [creator] WARNING: Could not register reflection metadata for org.springframework.boot.autoconfigure.transaction.jta.BitronixJtaConfiguration. Reason: java.lang.NoClassDefFoundError: bitronix/tm/Configuration. [INFO] [creator] 01:00:52.940 [ForkJoinPool-2-worker-1] DEBUG org.jboss.logging - Logging Provider: org.jboss.logging.Log4j2LoggerProvider [INFO] [creator] Error: Image build request failed with exit status 137 [INFO] [creator] unable to invoke layer creator [INFO] [creator] unable to contribute native-image layer [INFO] [creator] error running build [INFO] [creator] exit status 137 [INFO] [creator] ERROR: failed to build: exit status 1 [INFO] ------------------------------------------------------------------------ [INFO] BUILD FAILURE [INFO] ------------------------------------------------------------------------
AOTコンパイルは分散、並列化できないのでCPUとメモリの両方がボトルネックになる。 そもそも時間がかかりすぎるという問題もある。 解決するにはハイスペックマシンを用意するしかないので、頻繁にビルドを繰り返す開発プロジェクトに導入できるかは疑問。
native-imageに渡す引数はspring-boot-maven-pluginの設定にBP_NATIVE_IMAGE_BUILD_ARGUMENTSで指定する。
結局ヒープサイズ指定を32GBにしても成功しなかった。
そもそもpaketo-buildpacksコンテナを実行する環境には32GBもメモリを割り当ててないからかもしれない。
diff --git a/samples/data-jpa/pom.xml b/samples/data-jpa/pom.xml index 4187cf63..b6535097 100644 --- a/samples/data-jpa/pom.xml +++ b/samples/data-jpa/pom.xml @@ -114,6 +114,14 @@ <plugin> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-maven-plugin</artifactId> + <configuration> + <image> + <builder>paketobuildpacks/builder:tiny</builder> + <env> + <BP_NATIVE_IMAGE_BUILD_ARGUMENTS>-J-Xmx32G</BP_NATIVE_IMAGE_BUILD_ARGUMENTS> + </env> + </image> + </configuration> </plugin> <plugin> <groupId>org.hibernate.orm.tooling</groupId>
[OK] samplesの何かで動作を確認
samples/data-jpaで実験。
ただしAWS EC2(r5.2xlarge, vCPU=8, RAM=64GiB)で実行する。 時間もリソースも金で解決できるんですよ。
準備
$ uname -a
Linux ip-10-0-0-80.ap-northeast-1.compute.internal 4.14.219-164.354.amzn2.x86_64 #1 SMP Mon Feb 22 21:18:39 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
$ free -h
total used free shared buff/cache available
Mem: 62G 504M 57G 500K 4.4G 61G
Swap: 0B 0B 0B
$ sudo yum update -y
$ sudo yum install -y git
$ sudo amazon-linux-extras install docker
$ sudo usermod -a -G docker ec2-user
$ sudo systemctl enable docker
$ sudo systemctl start docker
$ curl -s "https://get.sdkman.io" | bash
$ source ~/.sdkman/bin/sdkman-init.sh
$ sdk install java 21.0.0.2.r11-grl
$ sdk install maven install 3.6.3
実験
成功した。 メモリは9.3GB以上必要だったようだ。
$ git clone https://github.com/spring-projects-experimental/spring-native $ cd spring-native/samples/data-jpa $ mvn spring-boot:build-image <snip> <snip> <snip> [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (clinit): 2,413.81 ms, 7.15 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (typeflow): 62,320.78 ms, 7.15 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (objects): 58,314.63 ms, 7.15 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (features): 11,451.10 ms, 7.15 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] analysis: 140,293.14 ms, 7.15 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] universe: 4,119.72 ms, 7.26 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (parse): 9,142.60 ms, 7.28 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (inline): 12,394.42 ms, 8.97 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] (compile): 44,175.39 ms, 9.39 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] compile: 71,024.26 ms, 9.39 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] image: 8,853.52 ms, 9.30 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] write: 1,264.68 ms, 9.30 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/app.main.SampleApplication:176] [total]: 233,022.78 ms, 9.30 GB [INFO] [creator] Removing bytecode [INFO] [creator] Process types: [INFO] [creator] native-image: /workspace/app.main.SampleApplication (direct) [INFO] [creator] task: /workspace/app.main.SampleApplication (direct) [INFO] [creator] web: /workspace/app.main.SampleApplication (direct) [INFO] [creator] ===> EXPORTING [INFO] [creator] Adding 1/1 app layer(s) [INFO] [creator] Adding layer 'launcher' [INFO] [creator] Adding layer 'config' [INFO] [creator] Adding layer 'process-types' [INFO] [creator] Adding label 'io.buildpacks.lifecycle.metadata' [INFO] [creator] Adding label 'io.buildpacks.build.metadata' [INFO] [creator] Adding label 'io.buildpacks.project.metadata' [INFO] [creator] Adding label 'org.opencontainers.image.title' [INFO] [creator] Adding label 'org.opencontainers.image.version' [INFO] [creator] Adding label 'org.springframework.boot.spring-configuration-metadata.json' [INFO] [creator] Adding label 'org.springframework.boot.version' [INFO] [creator] Setting default process type 'web' [INFO] [creator] *** Images (cc33ab8d5de7): [INFO] [creator] docker.io/library/data-jpa:0.0.1-SNAPSHOT [INFO] [creator] Adding cache layer 'paketo-buildpacks/graalvm:jdk' [INFO] [creator] Adding cache layer 'paketo-buildpacks/native-image:native-image' [INFO] [INFO] Successfully built image 'docker.io/library/data-jpa:0.0.1-SNAPSHOT'
前の例より少し大きくなっている(137MB)。
そしてやはり起動は高速だ。
Started SampleApplication in 0.114 seconds (JVM running for 0.115)
$ docker images | grep data-jpa data-jpa 0.0.1-SNAPSHOT cc33ab8d5de7 41 years ago 137MB $ docker run -d --name data-jpa -p 8080:8080 data-jpa:0.0.1-SNAPSHOT e72516c73a31d90078c0b88effd2c9d9ab9c9ca5911bc18bd513f1d65c52baeb $ docker logs --tail=10 data-jpa 2021-03-12 04:27:53.878 INFO 1 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2021-03-12 04:27:53.903 WARN 1 --- [ main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 2021-03-12 04:27:53.911 INFO 1 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor' 2021-03-12 04:27:53.915 INFO 1 --- [ main] o.s.w.s.f.support.RouterFunctionMapping : Mapped (GET && /) -> app.main.SampleApplication$$Lambda$1e60cb8412269e314b131e1c351c5acea34567f4@75858ac2 Mar 12, 2021 4:27:53 AM org.apache.coyote.AbstractProtocol start INFO: Starting ProtocolHandler ["http-nio-8080"] 2021-03-12 04:27:53.923 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2021-03-12 04:27:53.924 INFO 1 --- [ main] app.main.SampleApplication : Started SampleApplication in 0.114 seconds (JVM running for 0.115)
動作確認してみる。
最初のリクエストを受け付けたときだけdispatcherServletを初期化してる。
spring-boot-starter-webfluxはspring-boot-starter-webとは初期構成が異なるんだと思う。
リクエストを受け付けるたびに
dispatcherServletを初期化してるのはなんでだろう :thinking_face:
$ curl -s localhost:8080/; echo
{"value":"Hello"}
$ curl -s localhost:8080/; echo
{"value":"Hello"}
$ docker logs --tail=10 data-jpa
2021-03-12 04:34:31.249 INFO 1 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor'
2021-03-12 04:34:31.253 INFO 1 --- [ main] o.s.w.s.f.support.RouterFunctionMapping : Mapped (GET && /) -> app.main.SampleApplication$$Lambda$1e60cb8412269e314b131e1c351c5acea34567f4@d127876
Mar 12, 2021 4:34:31 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-nio-8080"]
2021-03-12 04:34:31.262 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2021-03-12 04:34:31.262 INFO 1 --- [ main] app.main.SampleApplication : Started SampleApplication in 0.115 seconds (JVM running for 0.116)
Mar 12, 2021 4:35:04 AM org.apache.catalina.core.ApplicationContext log
INFO: Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-03-12 04:35:04.896 INFO 1 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-03-12 04:35:04.897 INFO 1 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
[OK] Spring Initializrでプロジェクトを作って動作を確認
Spring Initializrで以下のコンポーネントを選択してプロジェクトを作成spring-nativespring-boot-starter-webspring-boot-starter-securityspring-boot-starter-data-jpah2
- ちょっとだけ設定と実装を追加
引き続きEC2で試すことにする。 ちゃんと成功した。
$ curl -fsSL --output demo.zip 'https://www.dropbox.com/s/xn0nfhqjb86lxp6/demo.zip?dl=0' $ unzip -q demo.zip $ cd demo $ mvn spring-boot:build-image <snip> <snip> <snip> [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (clinit): 2,669.42 ms, 5.99 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (typeflow): 54,900.98 ms, 5.99 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (objects): 84,588.13 ms, 5.99 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (features): 13,431.18 ms, 5.99 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] analysis: 162,606.05 ms, 5.99 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] universe: 4,543.12 ms, 5.88 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (parse): 15,612.61 ms, 6.90 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (inline): 18,884.95 ms, 8.12 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] (compile): 53,247.44 ms, 8.66 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] compile: 95,278.63 ms, 8.71 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] image: 13,747.40 ms, 8.72 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] write: 1,646.05 ms, 8.72 GB [INFO] [creator] [/layers/paketo-buildpacks_native-image/native-image/com.example.demo.DemoApplication:162] [total]: 284,598.43 ms, 8.72 GB [INFO] [creator] Removing bytecode [INFO] [creator] Process types: [INFO] [creator] native-image: /workspace/com.example.demo.DemoApplication (direct) [INFO] [creator] task: /workspace/com.example.demo.DemoApplication (direct) [INFO] [creator] web: /workspace/com.example.demo.DemoApplication (direct) [INFO] [creator] ===> EXPORTING [INFO] [creator] Adding 1/1 app layer(s) [INFO] [creator] Reusing layer 'launcher' [INFO] [creator] Adding layer 'config' [INFO] [creator] Reusing layer 'process-types' [INFO] [creator] Adding label 'io.buildpacks.lifecycle.metadata' [INFO] [creator] Adding label 'io.buildpacks.build.metadata' [INFO] [creator] Adding label 'io.buildpacks.project.metadata' [INFO] [creator] Adding label 'org.opencontainers.image.title' [INFO] [creator] Adding label 'org.opencontainers.image.version' [INFO] [creator] Adding label 'org.springframework.boot.spring-configuration-metadata.json' [INFO] [creator] Adding label 'org.springframework.boot.version' [INFO] [creator] Setting default process type 'web' [INFO] [creator] *** Images (745609869101): [INFO] [creator] com.example/demo:0.0.1-SNAPSHOT [INFO] [creator] Reusing cache layer 'paketo-buildpacks/graalvm:jdk' [INFO] [creator] Adding cache layer 'paketo-buildpacks/native-image:native-image' [INFO] [INFO] Successfully built image 'com.example/demo:0.0.1-SNAPSHOT'
前の例より少し大きくなっている(176MB)。
そしてやはり起動は高速だ。
Started DemoApplication in 0.248 seconds (JVM running for 0.249)
$ docker images com.example/demo REPOSITORY TAG IMAGE ID CREATED SIZE com.example/demo 0.0.1-SNAPSHOT 745609869101 41 years ago 176MB $ docker run -d --name demo -p 8080:8080 com.example/demo:0.0.1-SNAPSHOT e72516c73a31d90078c0b88effd2c9d9ab9c9ca5911bc18bd513f1d65c52baeb $ docker logs --tail=10 demo Hibernate: create sequence hibernate_sequence start with 1 increment by 1 2021-03-12 07:26:02.561 INFO 1 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform] 2021-03-12 07:26:02.561 INFO 1 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2021-03-12 07:26:02.586 WARN 1 --- [ main] JpaBaseConfiguration$JpaWebConfiguration : spring.jpa.open-in-view is enabled by default. Therefore, database queries may be performed during view rendering. Explicitly configure spring.jpa.open-in-view to disable this warning 2021-03-12 07:26:02.689 INFO 1 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure any request with [org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@60450f0a, org.springframework.security.web.context.SecurityContextPersistenceFilter@5494e33d, org.springframework.security.web.header.HeaderWriterFilter@47241e24, org.springframework.security.web.authentication.logout.LogoutFilter@66bb42a0, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@722091c3, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@61ff4cbb, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@1efca9f3, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@233b0d7a, org.springframework.security.web.session.SessionManagementFilter@531dc996, org.springframework.security.web.access.ExceptionTranslationFilter@4542c3e3, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@439ab877] 2021-03-12 07:26:02.697 INFO 1 --- [ main] o.s.s.concurrent.ThreadPoolTaskExecutor : Initializing ExecutorService 'applicationTaskExecutor' Mar 12, 2021 7:26:02 AM org.apache.coyote.AbstractProtocol start INFO: Starting ProtocolHandler ["http-nio-8080"] 2021-03-12 07:26:02.711 INFO 1 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2021-03-12 07:26:02.712 INFO 1 --- [ main] com.example.demo.DemoApplication : Started DemoApplication in 0.248 seconds (JVM running for 0.249)
動作確認してみる。だいたいよさそうだ。
$ curl --user test:test -s localhost:8080/book; echo
[]
$ curl --user test:test --request POST --header 'Content-Type: application/json' -d '{"title":"test 001"}' -s localhost:8080/book; echo
{"id":1,"title":"test 001"}
$ curl --user test:test --request POST --header 'Content-Type: application/json' -d '{"title":"test 002"}' -s localhost:8080/book; echo
{"id":2,"title":"test 002"}
$ curl --user test:test -s localhost:8080/book; echo
[{"id":1,"title":"test 001"},{"id":2,"title":"test 002"}]
$ curl --user test:test --request PUT --header 'Content-Type: application/json' -d '{"title":"test 001u1"}' -s localhost:8080/book?id=1; echo
{"id":1,"title":"test 001u1"}
$ curl --user test:test --request DELETE -s localhost:8080/book?id=2; echo
2
$ curl --user test:test -s localhost:8080/book; echo
[{"id":1,"title":"test 001u1"}]
$ curl -s localhost:8080/book; echo
{"timestamp":"2021-03-12T07:28:35.328+00:00","status":401,"error":"Unauthorized","message":"","path":"/book"}
$ docker logs --tail=10 demo
Hibernate: call next value for hibernate_sequence
Hibernate: insert into book (title, id) values (?, ?)
Hibernate: call next value for hibernate_sequence
Hibernate: insert into book (title, id) values (?, ?)
Hibernate: select book0_.id as id1_0_, book0_.title as title2_0_ from book book0_
Hibernate: select book0_.id as id1_0_0_, book0_.title as title2_0_0_ from book book0_ where book0_.id=?
Hibernate: update book set title=? where id=?
Hibernate: select book0_.id as id1_0_0_, book0_.title as title2_0_0_ from book book0_ where book0_.id=?
Hibernate: delete from book where id=?
Hibernate: select book0_.id as id1_0_, book0_.title as title2_0_ from book book0_
