Q&A
・tomcatには複数の種類のログがあります。どのログを見ましたか？warをデプロイした際に503が出るケースで最初に疑うのはデプロイが正常にできているかどうかです。
・CPUやディスク使用率が高かったとのことですが、ずっと高いままでしたか？デプロイ時にはJSPのコンパイルなども行われるため、一時的に負荷が高くなります。
お世話になります。
Spring Bootで作成したwarファイルをゲストOSのtomcatにデプロイしたいのですが、
warファイルをtomcat/webappsにおいてtomcatを起動したところ、今まで正常に動いていたtomcatが動かなくなり、503エラーがでてしまいました。
logを見てもエラーは見つからず、warファイルを配置しないでtomcatを実行したときはCPU,ディスク使用率はほとんど0なのに、配置したときは、ともに100%になるので、サーバーに負荷がかかっているのが原因なのだろうと推測したのですが、warファイルの大きさは40MB程度なので、そこまで負荷がかかるとは思えません。
また、tomcatはapache2と連携していて、warファイルを配置するまでは問題なく動いていて、
warファイルについても、logを見る限りエラーは見つかりませんでした。
調べたところ、
「javaのバグなので、JAVA_OPTSという環境変数を設定してからtomcatを実行すればよい」
という記事が出てきたのですが、設定できているのかわからず、実行しても、動かないままでした。
何をすればtomcatが動くようになるでしょうか。
環境
ゲストOS:ubuntu(vagrant)
javaのバージョン:tomcat,war共にopenjdk-11
tomcatのバージョン：9.0.52.0
[catalina.out]
. ____ _ __ _ _ /\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ / _` | \ \ \ \ \/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.5.2) 2021-09-01 09:31:28.717 INFO 2421 --- [ main] com.horaire.SampleApplication : No active profile set, falling back to default profiles: default NOTE: Picked up JDK_JAVA_OPTIONS: --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED (略) . ____ _ __ _ _ /\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ / _` | \ \ \ \ \/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.5.2) 2021-09-01 09:36:38.502 INFO 2675 --- [ main] com.horaire.SampleApplication : Starting SampleApplication using Java 11.0.11 on ubuntu-hirsute with PID 2675 (/opt/tomcat/webapps/horaire-0.0.1-SNAPSHOT/WEB-INF/classes started by tomcat in /) 2021-09-01 09:36:38.514 INFO 2675 --- [ main] com.horaire.SampleApplication : No active profile set, falling back to default profiles: default 2021-09-01 09:36:44.398 INFO 2675 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode. 2021-09-01 09:36:44.977 INFO 2675 --- [ main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 492 ms. Found 5 JPA repository interfaces. 2021-09-01 09:36:48.357 INFO 2675 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 9634 ms 2021-09-01 09:36:49.993 INFO 2675 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2021-09-01 09:36:53.806 INFO 2675 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2021-09-01 09:36:54.455 INFO 2675 --- [ main] o.hibernate.jpa.internal.util.LogHelper : HHH000204: Processing PersistenceUnitInfo [name: default] 2021-09-01 09:36:55.123 INFO 2675 --- [ main] org.hibernate.Version : HHH000412: Hibernate ORM core version 5.4.32.Final 2021-09-01 09:36:56.138 INFO 2675 --- [ main] o.hibernate.annotations.common.Version : HCANN000001: Hibernate Commons Annotations {5.1.2.Final} 2021-09-01 09:36:56.851 INFO 2675 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.MySQLDialect 2021-09-01 09:37:07.091 INFO 2675 --- [ main] o.h.e.t.j.p.i.JtaPlatformInitiator : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform] 2021-09-01 09:37:07.367 INFO 2675 --- [ main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default' 2021-09-01 09:46:20.484 WARN 2675 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m54s521ms250µs498ns). 2021-09-01 09:48:25.859 WARN 2675 --- [l-1 housekeeper] com.zaxxer.hikari.pool.HikariPool : HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=2m25s822ms710µs20ns).
※追加（下はbootじゃないほうのwarファイルの場合のlogです。）
01-Sep-2021 14:07:33.242 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.security.egd=file:/dev/./urandom org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib] 01-Sep-2021 14:07:34.704 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-127.0.0.1-8009"] 01-Sep-2021 14:07:34.805 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [2759] milliseconds 01-Sep-2021 14:07:35.001 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina] 01-Sep-2021 14:07:35.002 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.52] 01-Sep-2021 14:07:35.060 INFO [main] org.apache.catalina.startup.HostConfig.deployWAR Deploying web application archive [/opt/tomcat/webapps/horaire.war] 01-Sep-2021 14:07:41.574 INFO [main] org.apache.jasper.servlet.TldScanner.scanJars At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time. . ____ _ __ _ _ /\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ / _` | \ \ \ \ \/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v2.5.2) 2021-09-01 14:07:44.855 INFO 2554 --- [ main] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG' （略） 2021-09-01 14:08:09.468 INFO 2554 --- [ main] org.hibernate.dialect.Dialect : HHH000400: Using dialect: org.hibernate.dialect.MySQLDialect
回答ありがとうございます。
1.catalina.outのログを見ました。
2.そうです。20分ほど待ったのですが、ずっと高いままでした。
warファイルの作成手順をご提示ください。
ログを見る限りでは、warファイルがjarファイルと同じ手順で作成され、tomcatが組み込まれている状態になっていると思われます。
返信ありがとうございます。
自分は、
https://qiita.com/TEBASAKI/items/7a22c8b6ac6eb5f1c304
このサイトを参考にして、
①MainクラスにSpringBootServletInitializerを継承させ、SpringApplicationBuilderをOverrideする。
②build.gradleにwar pluginを追加。
③、dependeinciesにrovidedRuntime 'org.springframework.boot:spring-boot-starter-tomcat' を追加。
③gradleタスクでwarファイルを作成
という手順で行いました。一応tomcatが組み込まれないように設定したはずです。
それと、gradleタスクを実行するときに、warかbootwarかで迷ってboot warにしたのですけれど、それが原因なのでしょうか。（logはboot warです。）どちらにしろtomcatは動きませんでしたが。
お手数をおかけしますが、ログのどこの部分を見て組み込み式になているとわかったのか教えていただけませんか？
「ログのどこの部分を見て」は、ログの先頭がspringのAsciiArtになっているのを見て、です。
tomcatのログは、tomcatの起動情報から始まるはずですから。
追加いただいたログの場合、org.apache.catalina.startup~と、tomcat用のクラスに関する記述から開始されています。
そうですか…tomcatが取り組まれないように設定したはずなのですが…
dependenciesにprovidedRuntime と設定する以外で組み込まれないように設定する方法がおれば教えていただきたいです。
MySQLを使わない、単純なSpringbootアプリのwarファイルをデプロイしたところ、問題なく動いたので、MySQLの問題になると思います。
進展があったら報告させていただきます。
お騒がせしました。メモリー不足が原因でした。
自己解決
