地球は常に一定の質量を保っているわけではなく、宇宙から飛来した物体が隕石として地球に降り注ぐこともあれば、大気が宇宙空間に流出したり月へ送り込まれたりすることもあります。そこで、「地球の質量は次第に減っているのか、それとも増えているのか?」という疑問について、科学系メディアのLive Scienceが解説しています。
⇧ う、う~ん、地球がダイエットしてるのリバウンドしてるかも気になるけど、雪が降って寒さが半端ないほうが気になる今日この頃です。
というわけで、Javaについてです。
レッツトライ~。
Javaで外部プロセスを実施するって?
curlコマンドとかをJavaプログラミングの中で実行できたりするのかな?って気になって調べてみたところ、
Java1.4以前はRuntimeを利用しておりましたが、1.5以降からはRuntimeクラスではなくProcessBuilderクラスが推奨されます。
⇧ 上記サイト様によりますと、ProcessBuilderっていうJavaの標準APIで実現可能な模様。
Javaの標準APIのドキュメントで、ProcessBuilderを確認してみると、
このクラスは、オペレーティング・システムのプロセスの作成に使用されます。
⇧ なんか、サラッと言ってるけど、上記が事実だとすると、「OS(Operating System)」で実現できるプロセスのすべてが対象ってことなのだろうか?
だとしたら、驚き桃の木山椒の木、ですな。
Javaの標準APIのProcessBuilderで外部プロセスを実施してみる
というわけで、
⇧ curlを実現できるということで、試してみたいと思います。
今回は、Spring Bootのプロジェクトに対して外部プロセスを実施してみたいと思います。Spring Bootのプロジェクトでは、PostgreSQLやQuartzを利用していきます。
まずは、Eclipse側で「Spring Boot」のプロジェクトを作成。(「Spring スターター・プロジェクト」が表示されてない場合は、「その他(O)」を選択して、「Spring Boot」から選択すればOK)
「Java バージョン:」を17にしてみたんだけど、EclipseのバージョンによってはJava 17が同梱されてなくても、選択できるので注意。(後述してますが、自分の使ってるEclipseにはJava 17が入ってなかったので、結局、Java 8を使うように変更してます、選べるようになってるから利用できるもんだと思ってしまうよね...)
ここも、結局、後で他にも追加することになるのだけど、一旦、以下の依存関係を追加しておきます。
「完了(F)」を押下。
Java 17でプロジェクト作ってみたら、エラー出るというね...
説明 リソース パス ロケーション タイプ プロジェクト 'quartz-boot-thread' のクラスパス・コンテナー 'JRE システム・ライブラリー [JavaSE-17]' がアンバインドされています quartz-boot-thread ビルド・パス ビルド・パス問題
一旦、「ライブラリー(L)」タブで、「JRE システム・ライブラリー」を「除去(R)」で。
「ライブラリーの追加(I)...」を選択。
「JRE システム・ライブラリー」を選択して「次へ(N)>」押下。
「システム・ライブラリー」のラジオボタンが「ワークスペースのデフォルト JRE(D)(java11)」になってしまっているので、
「代替 JRE(J):」で、JREを選ぼうとしたら、まさかのインストールされてないという...
Eclipseに同梱されてるJavaを確認してみたところ、Eclipseのバージョンが古いせいか、
そもそも、Java 17は同梱されとらんのだが...
というか、Eclipseで「Spring スターター・プロジェクト」作成するときに、Java 17を選べてしまうから、てっきりJava 17が同梱されてるもんだと思い込んでしまうのだが...
今回は、Java 8にしておきました。
「適用して閉じる」を押下。
というわけで、今回は、「Spring スターター・プロジェクト」で利用するJavaについては、Java 8を使うにしました。
なんか、「ウィンドウ(W)」>「設定(P)」の、
「Java」>「コンパイラー」の設定で、「プロジェクト固有の設定の構成...」のリンクをクリックしてみたところ、
さきほど、Java 8に設定したプロジェクトがあったので、「コンパイラー」で設定してる「JDK 準拠」>「デフォルトの準拠設定の使用(T)」にチェックが入っていて、「コンパイラー準拠レベル(I)」が11になってるのも良くないんかな?
まぁ、相変わらずEclipseはよく分からん部分が多いですな...
で、「build.gradle」のJavaのバージョンが17になったままになっているので、修正します、ここを合わせとかないと、『has been compiled by a more recent version of the Java Runtime (class file version 58.0), this version of the Java Runtime only recognizes class file versions up to 52.0』ってエラー出てアプリケーションが起動できなくなるので。
■修正前
plugins { id 'org.springframework.boot' version '2.6.3' id 'io.spring.dependency-management' version '1.0.11.RELEASE' id 'java' } group = 'com.example' version = '0.0.1-SNAPSHOT' sourceCompatibility = '17' configurations { compileOnly { extendsFrom annotationProcessor } } repositories { mavenCentral() } dependencies { implementation 'org.springframework.boot:spring-boot-starter-data-jpa' implementation 'org.springframework.boot:spring-boot-starter-quartz' implementation 'org.springframework.boot:spring-boot-starter-web' compileOnly 'org.projectlombok:lombok' developmentOnly 'org.springframework.boot:spring-boot-devtools' runtimeOnly 'org.postgresql:postgresql' annotationProcessor 'org.projectlombok:lombok' testImplementation 'org.springframework.boot:spring-boot-starter-test' } tasks.named('test') { useJUnitPlatform() }
■修正後
plugins { id 'org.springframework.boot' version '2.6.3' id 'io.spring.dependency-management' version '1.0.11.RELEASE' id 'java' } group = 'com.example' version = '0.0.1-SNAPSHOT' sourceCompatibility = '1.8' configurations { compileOnly { extendsFrom annotationProcessor } } repositories { mavenCentral() } dependencies { implementation 'org.springframework.boot:spring-boot-starter-data-jpa' implementation 'org.springframework.boot:spring-boot-starter-quartz' implementation 'org.springframework.boot:spring-boot-starter-web' compileOnly 'org.projectlombok:lombok' developmentOnly 'org.springframework.boot:spring-boot-devtools' runtimeOnly 'org.postgresql:postgresql' annotationProcessor 'org.projectlombok:lombok' testImplementation 'org.springframework.boot:spring-boot-starter-test' } tasks.named('test') { useJUnitPlatform() }
脱線しましたが、PostgreSQLに、QuartzのJobなどを保存するテーブルを作成するので、PostgreSQLをインストールしておきます。
PostgreSQLがインストールされてるかどうかは、インストールされてる場所にもよりますが、Windows環境であれば、whereコマンドで分かるっぽいです。
自分の環境では、バージョンの異なる3つのPostgreSQLをインストールしてますが、1つあればOKです。
⇧ 上記のGitHubのものを利用するので、ダウンロードしますが、先にダウンロードするSQLファイルを配置するフォルダを作成しておきます。
そしたらば、コマンドプロンプトを起動して、作成したフォルダに移動して、Quartz用のテーブル作成SQLファイルをGitHubからダウンロードしてきて配置。
プロジェクトを選択して、「F5キー」でリフレッシュすると、SQLファイルが配置されてるのが確認できます。
PostgreSQLにログインし、適当に、データベースを作成して、
先ほどのSQLファイルを実行します。
Quartz用のテーブルが作成されました。
テーブルを1つ追加。
Spring BootでQuartzを利用する場合に、ややこしいのが、
I'm using Quartz Scheduler in one of my projects. There are two main ways to create a Quartz job:
- implement
org.quartz.Job
class - extend
org.springframework.scheduling.quartz.QuartzJobBean
(which implements org.quartz.Job class)
The last part of the QuartzJobBean javadoc is confusing :
* Note that the preferred way to apply dependency injection to Job instances is via a JobFactory:
that is, to specify SpringBeanJobFactory as Quartz JobFactory (typically via
SchedulerFactoryBean.setJobFactory SchedulerFactoryBean's "jobFactory" property}).
This allows to implement dependency-injected Quartz Jobs without a dependency on Spring base classes.*
For a pure Spring (or SpringBoot) use, I suppose that it is better to extend QuartzJobBean. I'm right?
⇧ 上記サイト様の質問でも上がってる通り、実装方法が2つあるらしく、ネットの情報がなかなかカオスな状況ですと。
このあたりのサンプルをSpringがドキュメントとかに載せてくれてれば、混乱せずに済むんですが、相変わらず、初見殺しというか隅から隅までドキュメントを読み込んで自ら推測する必要があるってあたりが、疲弊させてくれますよね...
ちなみに、
The actual configuration work happens in the QuartzAutoConfiguration
class where the properties read by Spring are injected.
https://tagmerge.com/question/spring-quartz-thread-pool-count-is-not-changed
⇧という情報があり、「QuartzAutoConfiguration」ってクラスが無かったんだけど、「依存関係」として「spring-boot-autoconfigure」を追加する必要があったというね...
Spring BootでQuartzを使うための必要な情報が分かり辛過ぎる...
「quartz.properties」っていう、Quartzの設定情報についても、
⇧ Quartz公式のGitHubのサンプルの情報が少ないし...
ちなみに、
⇧ Quartzのバージョン3系からは、Java 11以上が必須らしいので要注意ですかね。
で、最終的な、Eclipse側のプロジェクト構成は以下のようになりました。
各ファイルの内容は以下のようになりました。
■/quartz-boot-thread/build.gradle
plugins { id 'org.springframework.boot' version '2.6.3' id 'io.spring.dependency-management' version '1.0.11.RELEASE' id 'java' } group = 'com.example' version = '0.0.1-SNAPSHOT' sourceCompatibility = '1.8' configurations { compileOnly { extendsFrom annotationProcessor } } repositories { mavenCentral() } dependencies { implementation 'org.springframework.boot:spring-boot-starter-data-jpa' implementation 'org.springframework.boot:spring-boot-starter-quartz' implementation 'org.springframework.boot:spring-boot-starter-web' compileOnly 'org.projectlombok:lombok' developmentOnly 'org.springframework.boot:spring-boot-devtools' runtimeOnly 'org.postgresql:postgresql' annotationProcessor 'org.projectlombok:lombok' testImplementation 'org.springframework.boot:spring-boot-starter-test' // https://mvnrepository.com/artifact/com.mchange/c3p0 implementation group: 'com.mchange', name: 'c3p0', version: '0.9.5.5' // https://mvnrepository.com/artifact/org.springframework.boot/spring-boot-autoconfigure implementation group: 'org.springframework.boot', name: 'spring-boot-autoconfigure', version: '2.6.3' } tasks.named('test') { useJUnitPlatform() }
■/quartz-boot-thread/src/main/resources/application.properties
server.port=8088 # Postgresqlの接続設定 spring.datasource.driver-class-name=org.postgresql.Driver spring.datasource.url=jdbc:postgresql://localhost:5434/test spring.datasource.username=postgres spring.datasource.password=postgres #============================================================== # QUARTZ Configuration #============================================================== spring.quartz.job-store-type=jdbc spring.quartz.jdbc.initialize-schema=never spring.quartz.overwrite-existing-jobs=true spring.quartz.properties.org.quartz.scheduler.instanceName=TestScheduler spring.quartz.properties.org.quartz.jobStore.driverDelegateClass=org.quartz.impl.jdbcjobstore.PostgreSQLDelegate spring.quartz.properties.org.quartz.scheduler.instanceId=AUTO spring.quartz.properties.org.quartz.threadPool.class=org.quartz.simpl.SimpleThreadPool spring.quartz.properties.org.quartz.threadPool.threadCount=50 spring.quartz.properties.org.quartz.threadPool.threadPriority=5 spring.quartz.properties.org.quartz.threadPool.threadsInheritContextClassLoaderOfInitializingThread=true spring.quartz.properties.org.quartz.jobStore.misfireThreshold=60000 spring.quartz.properties.org.quartz.jobStore.class=org.quartz.impl.jdbcjobstore.JobStoreTX spring.quartz.properties.org.quartz.jobStore.useProperties=true spring.quartz.properties.org.quartz.jobStore.tablePrefix=qrtz_ spring.quartz.properties.org.quartz.jobStore.isClustered=true spring.quartz.properties.org.quartz.jobStore.clusterCheckinInterval=5000 #============================================================================ # Configure Datasources #============================================================================ spring.quartz.properties.org.quartz.jobStore.dataSource=myDS spring.quartz.properties.org.quartz.dataSource.myDS.driver=org.postgresql.Driver spring.quartz.properties.org.quartz.dataSource.myDS.URL=jdbc:postgresql://localhost:5434/test spring.quartz.properties.org.quartz.dataSource.myDS.user= postgres spring.quartz.properties.org.quartz.dataSource.myDS.password=postgres spring.quartz.properties.org.quartz.dataSource.myDS.maxConnections= 5 spring.quartz.properties.org.quartz.dataSource.myDS.validationQuery=select 0
⇧ application.propertiesで、サーバーのポート番号やデータベースの設定などは、ご自身の環境のものに合わせてください。
■/quartz-boot-thread/src/main/java/com/example/demo/entity/BaseEntity.java
package com.example.demo.entity; import java.time.OffsetDateTime; import javax.persistence.Column; import javax.persistence.MappedSuperclass; import lombok.Data; @Data @MappedSuperclass public class BaseEntity { @Column(name="created", columnDefinition = "TIMESTAMP DEFAULT CURRENT_TIMESTAMP") private OffsetDateTime created; @Column(name="updated") private OffsetDateTime updated; }
■/quartz-boot-thread/src/main/java/com/example/demo/entity/News.java
package com.example.demo.entity; import java.time.OffsetDateTime; import javax.persistence.Column; import javax.persistence.Entity; import javax.persistence.Id; import javax.persistence.Table; import lombok.AllArgsConstructor; import lombok.Data; import lombok.EqualsAndHashCode; import lombok.NoArgsConstructor; @EqualsAndHashCode(callSuper = true) @Data @NoArgsConstructor @AllArgsConstructor @Entity @Table(name="news", schema="public") public class News extends BaseEntity { @Id @Column(name="id", nullable=false) private Long id; @Column(name="title", nullable=false) private String title; @Column(name="context", nullable=false) private String context; @Column(name="publish_datetime", nullable=false) private OffsetDateTime publishDateTime; @Column(name="is_published", nullable=false, columnDefinition = "BOOLEAN DEFAULT CURRENT_TIMESTAMP") private Boolean isPublished; @Column(name="job_name", nullable=false) private String jobName; }
■/quartz-boot-thread/src/main/java/com/example/demo/repository/NewsRepository.java
package com.example.demo.repository; import java.time.OffsetDateTime; import org.springframework.data.jpa.repository.JpaRepository; import org.springframework.data.jpa.repository.Modifying; import org.springframework.data.jpa.repository.Query; import org.springframework.data.repository.CrudRepository; import org.springframework.data.repository.query.Param; import org.springframework.stereotype.Repository; import com.example.demo.entity.News; @Repository public interface NewsRepository extends JpaRepository<News, Long>, CrudRepository<News, Long> { @Query("SELECT coalesce(max(ns.id), 0) FROM News ns") Long getMaxId(); @Query(value = "SELECT nextval('news_id_seq')", nativeQuery = true) Long getNextSeriesId(); @Modifying @Query(value = "UPDATE News ns SET ns.isPublished = :isPublished, ns.updated = :updated WHERE ns.id = :id AND ns.jobName =:jobName", nativeQuery = false) void updateIsPublished(@Param(value = "id") Long newsId, @Param(value = "jobName") String jobName, @Param(value = "isPublished") Boolean isPublished, @Param(value = "updated") OffsetDateTime updated); }
■/quartz-boot-thread/src/main/java/com/example/demo/service/NewsServiceImpl.java
package com.example.demo.service; import java.time.Instant; import java.time.OffsetDateTime; import java.time.ZoneId; import java.util.Date; import java.util.UUID; import org.quartz.JobBuilder; import org.quartz.JobDataMap; import org.quartz.JobDetail; import org.quartz.Scheduler; import org.quartz.SchedulerException; import org.quartz.Trigger; import org.quartz.TriggerBuilder; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.stereotype.Service; import org.springframework.transaction.annotation.Transactional; import com.example.demo.batch.NewsBatchJob; import com.example.demo.entity.News; import com.example.demo.repository.NewsRepository; import lombok.extern.log4j.Log4j2; @Log4j2 @Service public class NewsServiceImpl { @Autowired private NewsRepository newsRepository; @Autowired private Scheduler scheduler; public News saveNews (String title, String context, OffsetDateTime publishDatetime) { String jobName = "news-job-" + UUID.randomUUID().toString(); Long id = newsRepository.getNextSeriesId(); News newsEntity = new News(); newsEntity.setId(id+1); newsEntity.setTitle(title); newsEntity.setContext(context); newsEntity.setPublishDateTime(publishDatetime); newsEntity.setIsPublished(false); newsEntity.setJobName(jobName); newsEntity.setCreated(OffsetDateTime.now()); newsRepository.saveAndFlush(newsEntity); scheduleNewsBatchJob(jobName, newsEntity); return newsEntity; } private void scheduleNewsBatchJob(String jobName, News newsEntity) { String jobGroup = "group-batch-news"; JobDataMap jobDataMap =new JobDataMap(); jobDataMap.put("newsId", String.valueOf(newsEntity.getId())); jobDataMap.put("jobName", newsEntity.getJobName()); JobDetail job = JobBuilder.newJob(NewsBatchJob.class) .usingJobData(jobDataMap) .withIdentity(jobName, jobGroup) .storeDurably() .build(); Trigger trigger = TriggerBuilder.newTrigger().forJob(job) .withIdentity(jobName, jobGroup) .startAt(Date.from(newsEntity.getPublishDateTime().toInstant())) .build(); try { scheduler.scheduleJob(job, trigger); } catch (SchedulerException e) { // TODO 自動生成された catch ブロック e.printStackTrace(); } } @Transactional public void executeNewsBatchJob(Long newsId, String jobName) { log.info("■□■バッチ処理を実行します。■□■"); log.info("【開始時刻】:{}", OffsetDateTime.ofInstant(Instant.ofEpochMilli(System.currentTimeMillis()), ZoneId.systemDefault())); log.info("news.id: {}, news.job_name: {}", newsId, jobName); // newsテーブルのis_publishedを更新 newsRepository.updateIsPublished(newsId, jobName, true); log.info("■□■バッチ処理が実行されました。■□■"); log.info("【終了時刻】:{}", OffsetDateTime.ofInstant(Instant.ofEpochMilli(System.currentTimeMillis()), ZoneId.systemDefault())); } }
■/quartz-boot-thread/src/main/java/com/example/demo/batch/NewsBatchJob.java
package com.example.demo.batch; import org.quartz.Job; import org.quartz.JobDataMap; import org.quartz.JobExecutionContext; import org.quartz.JobExecutionException; import org.springframework.beans.factory.annotation.Autowired; import com.example.demo.service.NewsServiceImpl; import lombok.extern.log4j.Log4j2; @Log4j2 public class NewsBatchJob implements Job { @Autowired private NewsServiceImpl newsServiceImpl; @Override public void execute(JobExecutionContext context) throws JobExecutionException { // TODO 自動生成されたメソッド・スタブ log.info("■□■バッチ処理を開始します。■□■"); JobDataMap jobDataMap = context.getJobDetail().getJobDataMap(); Long newsId = jobDataMap.getLong("newsId"); String jobName = jobDataMap.getString("jobName"); newsServiceImpl.executeNewsBatchJob(newsId, jobName); log.info("■□■バッチ処理が終了しました。■□■"); } }
■/quartz-boot-thread/src/main/java/com/example/demo/controller/NewsController.java
package com.example.demo.controller; import java.time.OffsetDateTime; import java.time.format.DateTimeFormatter; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.web.bind.annotation.PostMapping; import org.springframework.web.bind.annotation.RequestParam; import org.springframework.web.bind.annotation.RestController; import com.example.demo.entity.News; import com.example.demo.service.NewsServiceImpl; import lombok.extern.log4j.Log4j2; @Log4j2 @RestController public class NewsController { @Autowired private NewsServiceImpl newsServiceImpl; @PostMapping("/news") private News saveNews(@RequestParam(name = "title") String title , @RequestParam(name = "context") String context , @RequestParam(name = "publish_datetime", required=false) String publishDatetime) { // ,@DateTimeFormat(iso = DateTimeFormat.ISO.DATE_TIME)OffsetDateTime publishDatetime) { log.info("■□■リクエスト受付開始■□■"); DateTimeFormatter dateTimeFormatter = DateTimeFormatter.ISO_OFFSET_DATE_TIME; OffsetDateTime publishedDatetime = OffsetDateTime.parse(publishDatetime, dateTimeFormatter); News newsEntity = newsServiceImpl.saveNews(title, context, publishedDatetime); log.info("■□■リクエスト結果返却■□■"); return newsEntity; } }
■/quartz-boot-thread/src/main/java/com/example/demo/QuartzBootThreadApplication.java
package com.example.demo; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; @SpringBootApplication public class QuartzBootThreadApplication { public static void main(String[] args) { SpringApplication.run(QuartzBootThreadApplication.class, args); } }
実行しておきます。
で、今回の本題の外部プロセスを実施してみるについては、Eclipse側のSpring bootのアプリケーションにcurlコマンドを実行するJavaファイルを作成しました。
コーディングは以下のようになりました。curlコマンドの鬼畜仕様(日付の中の+記号をエンコードしておく必要がある、というか日付じゃなくても他にもエンコードが必要なケースがあるような気がする...調べきれてないけど)に気付かずに時間を無駄にしてしまいましたよ...3連休返して欲しい...
⇧ 上記サイト様によりますと、curlコマンドのオプションで回避できたらしい...もう少し早く知りたかった~、今回は力業でごまかしたけど、「--data-urlencode」オプション使った方が断然良い気がする~。
■C:\Users\Toshinobu\Desktop\soft_work\java_work\TestCurl\TestCurl.java
import java.io.IOException; import java.io.UnsupportedEncodingException; import java.net.URLEncoder; import java.time.OffsetDateTime; public class TestCurl { public static void main(String[] args) { String postURL = "http://localhost:8088/news"; String title = "test-title-"; String context = "test-context-"; String halfWidthSpace = " "; OffsetDateTime publishDatetime = OffsetDateTime.now().plusMinutes(5); StringBuilder sb = new StringBuilder(); for (int index = 0; index < 1000; index++) { try { sb.append("curl -X POST") .append(halfWidthSpace).append(postURL) .append(halfWidthSpace).append("--data") .append(halfWidthSpace) .append("\"") .append("title=").append(title).append(index) .append("&context=").append(context).append(index) .append("&publish_datetime=") .append(publishDatetime.toString().replace("+", URLEncoder.encode("+", "UTF-8"))) .append("\""); System.out.println(sb.toString()); Runtime.getRuntime().exec(sb.toString()); } catch (UnsupportedEncodingException e) { // TODO 自動生成された catch ブロック e.printStackTrace(); } catch (IOException e) { e.printStackTrace(); } sb.setLength(0); } } }
"C:\Eclipse-2020-06\pleiades-2020-06-java-win-64bit-jre_20200702\pleiades\java\8\bin\javac.exe" -encoding utf-8 TestCurl.java
classファイルを実行。
"C:\Eclipse-2020-06\pleiades-2020-06-java-win-64bit-jre_20200702\pleiades\java\8\bin\java.exe" TestCurl
Eclipse側のコンソールを確認すると、コントローラーの処理が実行されてるのが確認できます。
テーブルへの登録もされています。
■newsテーブル
■qrtz_triggersテーブル
■qrtz_simple_triggersテーブル
■qrtz_job_detailsテーブル
今回は、バッチ処理の実行タイミングを5分後にしてるので、5分後にEclipse側のコンソールを確認すると、バッチ処理が実行されたのを確認できます。
テーブルについても更新されてることが確認できました。
バッチ処理で時間のかかるような処理の場合にどうなるのかは分からないですが、今回のように、1行のレコードを更新するような単純な処理の場合は、バッチ処理のトリガー(開始時刻)が同じでも、1000件の処理がすべて実行されていました。
ただ、QuartzのTriggerは永続化がされてない原因がよく分からずです...qrtz_job_detailsテーブルのレコードは増えて行ってるから、Jobの永続化はできてるっぽい気はするんだけど...
Springの問題なのか、Quartzの問題なのか、毎度モヤモヤ感が半端ない...
本当に3連休を費やした価値ないですな...
2022年2月15日(火)追記:↓ ここから
application.propertiesにログの設定を追加してみたところ、
server.port=8088 # Postgresqlの接続設定 spring.datasource.driver-class-name=org.postgresql.Driver spring.datasource.url=jdbc:postgresql://localhost:5434/test spring.datasource.username=postgres spring.datasource.password=postgres spring.jpa.show-sql=true debug=true logging.level.org.springframework=DEBUG spring.jpa.open-in-view=false #============================================================== # QUARTZ Configuration #============================================================== spring.quartz.job-store-type=jdbc spring.quartz.jdbc.initialize-schema=never spring.quartz.overwrite-existing-jobs=true spring.quartz.properties.org.quartz.jobStore.dontSetAutoCommitFalse=false spring.quartz.properties.org.quartz.scheduler.instanceName=TestScheduler spring.quartz.properties.org.quartz.jobStore.driverDelegateClass=org.quartz.impl.jdbcjobstore.PostgreSQLDelegate spring.quartz.properties.org.quartz.scheduler.instanceId=AUTO spring.quartz.properties.org.quartz.threadPool.class=org.quartz.simpl.SimpleThreadPool spring.quartz.properties.org.quartz.threadPool.threadCount=50 spring.quartz.properties.org.quartz.threadPool.threadPriority=5 spring.quartz.properties.org.quartz.threadPool.threadsInheritContextClassLoaderOfInitializingThread=true spring.quartz.properties.org.quartz.jobStore.misfireThreshold=60000 spring.quartz.properties.org.quartz.jobStore.class=org.quartz.impl.jdbcjobstore.JobStoreTX spring.quartz.properties.org.quartz.jobStore.useProperties=true spring.quartz.properties.org.quartz.jobStore.tablePrefix=qrtz_ spring.quartz.properties.org.quartz.jobStore.isClustered=false spring.quartz.properties.org.quartz.jobStore.clusterCheckinInterval=5000 #============================================================================ # Configure Datasources #============================================================================ spring.quartz.properties.org.quartz.jobStore.dataSource=myDS spring.quartz.properties.org.quartz.dataSource.myDS.driver=org.postgresql.Driver spring.quartz.properties.org.quartz.dataSource.myDS.URL=jdbc:postgresql://localhost:5434/test spring.quartz.properties.org.quartz.dataSource.myDS.user= postgres spring.quartz.properties.org.quartz.dataSource.myDS.password=postgres spring.quartz.properties.org.quartz.dataSource.myDS.maxConnections= 5 spring.quartz.properties.org.quartz.dataSource.myDS.validationQuery=select 0
以下のようなエラーが出てました。
...省略 2022-02-15 22:14:31.907 DEBUG 15556 --- [io-8088-exec-99] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.saveAndFlush]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2022-02-15 22:14:32.409 DEBUG 15556 --- [io-8088-exec-99] o.s.orm.jpa.JpaTransactionManager : Opened new EntityManager [SessionImpl(1494702469<open>)] for JPA transaction 2022-02-15 22:14:32.409 DEBUG 15556 --- [o-8088-exec-126] o.s.web.servlet.DispatcherServlet : "ERROR" dispatch for POST "/error", parameters={masked} 2022-02-15 22:14:31.937 WARN 15556 --- [io-8088-exec-29] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 0, SQLState: null 2022-02-15 22:14:32.409 ERROR 15556 --- [io-8088-exec-29] o.h.engine.jdbc.spi.SqlExceptionHelper : HikariPool-5 - Connection is not available, request timed out after 30118ms. 2022-02-15 22:14:32.409 DEBUG 15556 --- [o-8088-exec-126] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController#error(HttpServletRequest) 2022-02-15 22:14:32.409 DEBUG 15556 --- [io-8088-exec-29] o.s.web.servlet.DispatcherServlet : Failed to complete request: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection 2022-02-15 22:14:31.937 WARN 15556 --- [o-8088-exec-153] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 0, SQLState: null 2022-02-15 22:14:32.410 ERROR 15556 --- [o-8088-exec-153] o.h.engine.jdbc.spi.SqlExceptionHelper : HikariPool-5 - Connection is not available, request timed out after 30118ms. 2022-02-15 22:14:32.410 DEBUG 15556 --- [o-8088-exec-126] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json] 2022-02-15 22:14:32.410 DEBUG 15556 --- [o-8088-exec-126] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Writing [{timestamp=Tue Feb 15 22:14:32 JST 2022, status=500, error=Internal Server Error, trace=org.springfr (truncated)...] 2022-02-15 22:14:32.410 DEBUG 15556 --- [o-8088-exec-153] o.s.web.servlet.DispatcherServlet : Failed to complete request: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection 2022-02-15 22:14:31.957 WARN 15556 --- [io-8088-exec-82] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 0, SQLState: null 2022-02-15 22:14:32.423 ERROR 15556 --- [io-8088-exec-82] o.h.engine.jdbc.spi.SqlExceptionHelper : HikariPool-5 - Connection is not available, request timed out after 30107ms. 2022-02-15 22:14:32.013 DEBUG 15556 --- [o-8088-exec-139] o.s.web.servlet.DispatcherServlet : POST "/news", parameters={masked} 2022-02-15 22:14:32.424 DEBUG 15556 --- [o-8088-exec-139] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.controller.NewsController#saveNews(String, String, String) 2022-02-15 22:14:32.424 INFO 15556 --- [o-8088-exec-139] c.e.demo.controller.NewsController : ■□■リクエスト受付開始■□■ 2022-02-15 22:14:32.424 DEBUG 15556 --- [o-8088-exec-139] tor$SharedEntityManagerInvocationHandler : Creating new EntityManager for shared EntityManager invocation 2022-02-15 22:14:32.424 DEBUG 15556 --- [o-8088-exec-139] org.hibernate.SQL : SELECT nextval('news_id_seq') Hibernate: SELECT nextval('news_id_seq') 2022-02-15 22:14:32.424 DEBUG 15556 --- [io-8088-exec-82] o.s.web.servlet.DispatcherServlet : Failed to complete request: org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection 2022-02-15 22:14:32.013 DEBUG 15556 --- [o-8088-exec-198] o.s.web.servlet.DispatcherServlet : POST "/news", parameters={masked} 2022-02-15 22:14:32.425 DEBUG 15556 --- [o-8088-exec-198] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.controller.NewsController#saveNews(String, String, String) 2022-02-15 22:14:32.425 INFO 15556 --- [o-8088-exec-198] c.e.demo.controller.NewsController : ■□■リクエスト受付開始■□■ 2022-02-15 22:14:32.013 DEBUG 15556 --- [io-8088-exec-66] o.s.web.servlet.DispatcherServlet : POST "/news", parameters={masked} 2022-02-15 22:14:32.013 DEBUG 15556 --- [o-8088-exec-141] o.s.web.servlet.DispatcherServlet : POST "/news", parameters={masked} 2022-02-15 22:14:32.425 DEBUG 15556 --- [io-8088-exec-66] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.controller.NewsController#saveNews(String, String, String) 2022-02-15 22:14:32.013 DEBUG 15556 --- [o-8088-exec-110] o.s.orm.jpa.JpaTransactionManager : Exposing JPA transaction as JDBC [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@8daea56] 2022-02-15 22:14:32.426 INFO 15556 --- [io-8088-exec-66] c.e.demo.controller.NewsController : ■□■リクエスト受付開始■□■ 2022-02-15 22:14:32.013 DEBUG 15556 --- [o-8088-exec-162] o.s.orm.jpa.JpaTransactionManager : Creating new transaction with name [org.springframework.data.jpa.repository.support.SimpleJpaRepository.saveAndFlush]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT 2022-02-15 22:14:32.426 DEBUG 15556 --- [o-8088-exec-162] o.s.orm.jpa.JpaTransactionManager : Opened new EntityManager [SessionImpl(373833315<open>)] for JPA transaction 2022-02-15 22:14:32.426 DEBUG 15556 --- [io-8088-exec-66] tor$SharedEntityManagerInvocationHandler : Creating new EntityManager for shared EntityManager invocation 2022-02-15 22:14:32.426 DEBUG 15556 --- [io-8088-exec-66] org.hibernate.SQL : SELECT nextval('news_id_seq') Hibernate: SELECT nextval('news_id_seq') 2022-02-15 22:14:32.014 DEBUG 15556 --- [io-8088-exec-52] o.s.web.servlet.DispatcherServlet : POST "/news", parameters={masked} 2022-02-15 22:14:32.040 WARN 15556 --- [io-8088-exec-22] o.h.engine.jdbc.spi.SqlExceptionHelper : SQL Error: 0, SQLState: null 2022-02-15 22:14:32.426 ERROR 15556 --- [io-8088-exec-22] o.h.engine.jdbc.spi.SqlExceptionHelper : HikariPool-5 - Connection is not available, request timed out after 30097ms. 2022-02-15 22:14:32.426 DEBUG 15556 --- [io-8088-exec-52] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.controller.NewsController#saveNews(String, String, String) 2022-02-15 22:14:32.426 INFO 15556 --- [io-8088-exec-52] c.e.demo.controller.NewsController : ■□■リクエスト受付開始■□■ 2022-02-15 22:14:32.427 DEBUG 15556 --- [io-8088-exec-52] tor$SharedEntityManagerInvocationHandler : Creating new EntityManager for shared EntityManager invocation 2022-02-15 22:14:32.427 DEBUG 15556 --- [io-8088-exec-22] o.s.web.servlet.DispatcherServlet : Failed to complete request: org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection 2022-02-15 22:14:32.427 DEBUG 15556 --- [io-8088-exec-52] org.hibernate.SQL : SELECT nextval('news_id_seq') Hibernate: SELECT nextval('news_id_seq') 2022-02-15 22:14:32.062 DEBUG 15556 --- [o-8088-exec-112] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit 2022-02-15 22:14:32.427 DEBUG 15556 --- [o-8088-exec-112] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(2140413707<open>)] 2022-02-15 22:14:32.429 ERROR 15556 --- [io-8088-exec-82] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection] with root cause java.sql.SQLTransientConnectionException: HikariPool-5 - Connection is not available, request timed out after 30107ms. at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696) ~[HikariCP-4.0.3.jar:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197) ~[HikariCP-4.0.3.jar:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-4.0.3.jar:na] at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-4.0.3.jar:na] at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.6.4.Final.jar:5.6.4.Final] ...省略
調べたところ、
⇧ 上記サイト様によりますと、コネクションプールの枯渇を引き起こしているということらしい。
今回は、実験的に間断なくcurlでリクエストして、INSERT文のSQLを実行しまくってるからコネクションプールの枯渇が起きても当然と言えば当然なのかもしれないけど...
2022年2月15日(火)追記:↑ ここまで
今回はこのへんで。