これは、なにをしたくて書いたもの?
以前Quartzについて調べた時に、Scheduler#shutdown
を呼び出す際に引数があるものを使い、かつtrue
に設定すると実行中のジョブが
ある場合は、ジョブが終了するまで待機するということを書きました。
JavaのジョブスケジューラーQuartzを試す - CLOVER🍀
確かにドキュメントにもそのように書かれているのですが、実際にどうなのか確認してみることにしました。
How-To: Shutting Down a Scheduler
Scheduler#shutdown
Scheduler
のシャットダウンに関するドキュメントはこちら。
How-To: Shutting Down a Scheduler
実行中のジョブが終了するまで待つ例、待たない例がそれぞれ書かれています。
待つ場合はこちら。
//shutdown() does not return until executing Jobs complete execution scheduler.shutdown(true);
待たない場合はこちら。
//shutdown() returns immediately, but executing Jobs continue running to completion scheduler.shutdown(); //or scheduler.shutdown(false);
Scheduler#shutdown
の引数ありのメソッドを使い、かつtrue
を指定するかどうかで動作が変わります。
こちらの動作を、スタンドアロン、クラスタリングをした時でそれぞれ見てみようと思います。
環境
今回の環境は、こちら。
$ java --version openjdk 17.0.8.1 2023-08-24 OpenJDK Runtime Environment (build 17.0.8.1+1-Ubuntu-0ubuntu122.04) OpenJDK 64-Bit Server VM (build 17.0.8.1+1-Ubuntu-0ubuntu122.04, mixed mode, sharing) $ mvn --version Apache Maven 3.9.4 (dfbb324ad4a7c8fb0bf182e6d91b0ae20e3d2dd9) Maven home: $HOME/.sdkman/candidates/maven/current Java version: 17.0.8.1, vendor: Private Build, runtime: /usr/lib/jvm/java-17-openjdk-amd64 Default locale: ja_JP, platform encoding: UTF-8 OS name: "linux", version: "5.15.0-84-generic", arch: "amd64", family: "unix"
クラスタリングを行う際のデータベースは、MySQLを使います。172.17.0.2で動作しているものとし、バージョンはこちら。
MySQL localhost:3306 ssl practice SQL > select version(); +-----------+ | version() | +-----------+ | 8.0.34 | +-----------+ 1 row in set (0.0007 sec)
ユーザーおよびデータベースは作成済みとします。
準備
Maven依存関係など。
<properties> <maven.compiler.source>17</maven.compiler.source> <maven.compiler.target>17</maven.compiler.target> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding> </properties> <dependencies> <dependency> <groupId>org.quartz-scheduler</groupId> <artifactId>quartz</artifactId> <version>2.3.2</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>2.0.9</version> </dependency> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-simple</artifactId> <version>2.0.9</version> </dependency> <dependency> <groupId>com.mysql</groupId> <artifactId>mysql-connector-j</artifactId> <version>8.0.33</version> <scope>runtime</scope> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-shade-plugin</artifactId> <version>3.5.1</version> <executions> <execution> <phase>package</phase> <goals> <goal>shade</goal> </goals> <configuration> <transformers> <transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer"> <mainClass>org.littlewings.quartz.shutdown.App</mainClass> </transformer> </transformers> </configuration> </execution> </executions> </plugin> </plugins> </build>
実行可能JARとして動作させることにします。
Quartzのテーブルを作成。
$ curl -sL https://raw.githubusercontent.com/quartz-scheduler/quartz/v2.3.2/quartz-core/src/main/resources/org/quartz/impl/jdbcjobstore/tables_mysql_innodb.sql | mysqlsh kazuhira@localhost:3306/practice --sql
ソースコードを作成する
まずは、Quartzのジョブを作成します。
毎分0秒、15秒、30秒、45秒に起動するジョブを作成し、各ジョブは30秒待機するものにします。
つまり、こういうものです。
src/main/java/org/littlewings/quartz/shutdown/HelloAt0Job.java
package org.littlewings.quartz.shutdown; import org.quartz.Job; import org.quartz.JobExecutionContext; import org.quartz.JobExecutionException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import java.time.LocalDateTime; import java.time.format.DateTimeFormatter; import java.util.concurrent.TimeUnit; public class HelloAt0Job implements Job { static final DateTimeFormatter DATE_TIME_FORMATTER = DateTimeFormatter.ofPattern("uuuu-MM-dd HH:mm:ss"); Logger logger = LoggerFactory.getLogger(HelloAt0Job.class); @Override public void execute(JobExecutionContext jobExecutionContext) throws JobExecutionException { logger.info("[{}] job start..., sleep 30sec", LocalDateTime.now().format(DATE_TIME_FORMATTER)); try { TimeUnit.SECONDS.sleep(30L); } catch (InterruptedException e) { } logger.info("Hello from {}", getClass().getSimpleName()); logger.info("[{}] job end", LocalDateTime.now().format(DATE_TIME_FORMATTER)); } }
同じ処理をするので、同じジョブを別のトリガーで登録すればいいのですが、今回はわかりやすいようにそれぞれ別のクラスにしました。
ログ出力時にわざわざ時刻を入れているのは、ログ設定を端折ってslf4j-simpleにしたからです…。
つまり、こうです。
src/main/java/org/littlewings/quartz/shutdown/HelloAt15Job.java
package org.littlewings.quartz.shutdown; import org.quartz.Job; import org.quartz.JobExecutionContext; import org.quartz.JobExecutionException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import java.time.LocalDateTime; import java.time.format.DateTimeFormatter; import java.util.concurrent.TimeUnit; public class HelloAt15Job implements Job { static final DateTimeFormatter DATE_TIME_FORMATTER = DateTimeFormatter.ofPattern("uuuu-MM-dd HH:mm:ss"); Logger logger = LoggerFactory.getLogger(HelloAt15Job.class); @Override public void execute(JobExecutionContext jobExecutionContext) throws JobExecutionException { logger.info("[{}] job start..., sleep 30sec", LocalDateTime.now().format(DATE_TIME_FORMATTER)); try { TimeUnit.SECONDS.sleep(30L); } catch (InterruptedException e) { } logger.info("Hello from {}", getClass().getSimpleName()); logger.info("[{}] job end", LocalDateTime.now().format(DATE_TIME_FORMATTER)); } }
あと2つは省略します。
public class HelloAt30Job implements Job { // 省略 } public class HelloAt45Job implements Job { // 省略 }
そして、main
メソッドを持ったクラス。
src/main/java/org/littlewings/quartz/shutdown/App.java
package org.littlewings.quartz.shutdown; import org.quartz.*; import org.quartz.impl.StdSchedulerFactory; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import java.io.Console; public class App { public static void main(String... args) { Logger logger = LoggerFactory.getLogger(App.class); Scheduler scheduler = null; boolean waitForJobsToComplete; boolean registerSchedule; if (args.length > 0) { waitForJobsToComplete = Boolean.parseBoolean(args[0]); if (args.length > 1) { registerSchedule = Boolean.parseBoolean(args[1]); } else { registerSchedule = true; } } else { waitForJobsToComplete = true; registerSchedule = true; } try { scheduler = StdSchedulerFactory.getDefaultScheduler(); if (registerSchedule) { logger.info("register schedule"); registerSchedules(scheduler); } logger.info("scheduler start, wait for jobs to complete = [{}], scheduler registered = [{}]", waitForJobsToComplete, registerSchedule); scheduler.start(); Console console = System.console(); console.readLine(); } catch (SchedulerException e) { e.printStackTrace(); } finally { if (scheduler != null) { try { logger.info("shutdown start..."); scheduler.shutdown(waitForJobsToComplete); logger.info("shutdown end"); } catch (SchedulerException e) { e.printStackTrace(); } } } } static void registerSchedules(Scheduler scheduler) throws SchedulerException { JobDetail jobDetail1 = JobBuilder .newJob(HelloAt0Job.class) .withIdentity("hello-at0-job", "job-group1") .build(); Trigger trigger1 = TriggerBuilder .newTrigger() .withIdentity("hello-at0-trigger", "trigger-group1") .withSchedule(CronScheduleBuilder.cronSchedule("0 * * * * ?")) .build(); JobDetail jobDetail2 = JobBuilder .newJob(HelloAt15Job.class) .withIdentity("hello-at15-job", "job-group1") .build(); Trigger trigger2 = TriggerBuilder .newTrigger() .withIdentity("hello-at15-trigger", "trigger-group1") .withSchedule(CronScheduleBuilder.cronSchedule("15 * * * * ?")) .build(); JobDetail jobDetail3 = JobBuilder .newJob(HelloAt30Job.class) .withIdentity("hello-at30-job", "job-group1") .build(); Trigger trigger3 = TriggerBuilder .newTrigger() .withIdentity("hello-at30-trigger", "trigger-group1") .withSchedule(CronScheduleBuilder.cronSchedule("30 * * * * ?")) .build(); JobDetail jobDetail4 = JobBuilder .newJob(HelloAt45Job.class) .withIdentity("hello-at45-job", "job-group1") .build(); Trigger trigger4 = TriggerBuilder .newTrigger() .withIdentity("hello-at45-trigger", "trigger-group1") .withSchedule(CronScheduleBuilder.cronSchedule("45 * * * * ?")) .build(); scheduler.scheduleJob(jobDetail1, trigger1); scheduler.scheduleJob(jobDetail2, trigger2); scheduler.scheduleJob(jobDetail3, trigger3); scheduler.scheduleJob(jobDetail4, trigger4); } }
コマンドライン引数で、「Scheduler
のシャットダウン時に実行中のジョブを待つかどうか」と「Scheduler
にジョブを登録するか」を
boolean
で指定するようにしています。
boolean waitForJobsToComplete; boolean registerSchedule; if (args.length > 0) { waitForJobsToComplete = Boolean.parseBoolean(args[0]); if (args.length > 1) { registerSchedule = Boolean.parseBoolean(args[1]); } else { registerSchedule = true; } } else { waitForJobsToComplete = true; registerSchedule = true; }
後者は、クラスタリング向けですね。
なにも指定しないと、「Scheduler
のシャットダウン時に実行中のジョブを待つ」、「Scheduler
にジョブを登録する」になります。
このあたりに影響します。
// Schedulerにジョブを登録 if (registerSchedule) { logger.info("register schedule"); registerSchedules(scheduler); } } finally { if (scheduler != null) { try { logger.info("shutdown start..."); // Schedulerのシャットダウン時に実行中のジョブを待つかどうかをbooleanで指定 scheduler.shutdown(waitForJobsToComplete); logger.info("shutdown end"); } catch (SchedulerException e) { e.printStackTrace(); } } }
どういうモードで実行しているかは、ログで表示します。
logger.info("scheduler start, wait for jobs to complete = [{}], scheduler registered = [{}]", waitForJobsToComplete, registerSchedule);
scheduler.start();
アプリケーションは、Enterを打つと停止を始めるようになっています。
Console console = System.console(); console.readLine();
ジョブの登録はこのあたりですが、省略します…。
static void registerSchedules(Scheduler scheduler) throws SchedulerException { JobDetail jobDetail1 = JobBuilder .newJob(HelloAt0Job.class) .withIdentity("hello-at0-job", "job-group1") .build(); Trigger trigger1 = TriggerBuilder .newTrigger() .withIdentity("hello-at0-trigger", "trigger-group1") .withSchedule(CronScheduleBuilder.cronSchedule("0 * * * * ?")) .build(); // 省略 }
毎分0秒、15秒、30秒、45秒に、実行に30秒かかるジョブが起動するようになります。
スタンドアロンで確認する
では、確認してみましょう。
パッケージング。
$ mvn package
実行。
$ java -jar target/-0.0.1-SNAPSHOT.jar
実行すると、こんな感じで進んでいきます。
[DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:27:30] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:27:45] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:28:00] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - Hello from HelloAt30Job [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:28:00] job end [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - Hello from HelloAt45Job [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:28:15] job end
1度やり直して、2つジョブが実行している間に止めてみましょう。デフォルトではジョブが終了するまで待つはずです。
結果はこちら。
[main] INFO org.littlewings.quartz.shutdown.App - scheduler start, wait for jobs to complete = [true], scheduler registered = [true] [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started. [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:30:45] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:31:00] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:31:15] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - Hello from HelloAt45Job [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:31:15] job end [main] INFO org.littlewings.quartz.shutdown.App - shutdown start... [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutting down. [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED paused. [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - Hello from HelloAt0Job [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:31:30] job end [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:31:45] job end [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutdown complete. [main] INFO org.littlewings.quartz.shutdown.App - shutdown end
空行があるところが、Enterを打った箇所です。
HelloAt45Job
のジョブが終了し、HelloAt0Job
とHelloAt15Job
が実行中に停止を始めたわけですが、確かに終了するまで待っています。
では、次は待たないようにしてみましょう。
$ java -jar target/app-0.0.1-SNAPSHOT.jar false
結果。
[main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED started. [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:33:45] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:34:00] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:34:15] job start..., sleep 30sec [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - Hello from HelloAt45Job [DefaultQuartzScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:34:15] job end [main] INFO org.littlewings.quartz.shutdown.App - shutdown start... [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutting down. [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED paused. [main] INFO org.quartz.core.QuartzScheduler - Scheduler DefaultQuartzScheduler_$_NON_CLUSTERED shutdown complete. [main] INFO org.littlewings.quartz.shutdown.App - shutdown end [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - Hello from HelloAt0Job [DefaultQuartzScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:34:30] job end [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [DefaultQuartzScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:34:45] job end
動作が変わり、Scheduler
自体はジョブの終了を待たなくなりました。
一方で、ジョブを無視して終了しているかというと、アクティブなスレッドが残っているのでJavaVMが終了しない状態になりましたね…。
実行中のジョブが強制的に止められるわけではないということも合わせてわかりましたが、Scheduler
の振る舞いは確認できました。
クラスタリングしてみる
クラスタリング用のプロパティファイルを作成。今回はデフォルトの名前(quartz.properties
)で作成せず、アプリケーションの実行時に
-Dorg.quartz.properties
システムプロパティで指定することにします。
src/main/resources/quartz-clustering.properties
org.quartz.scheduler.instanceName=ClusteredExampleScheduler org.quartz.scheduler.instanceId=AUTO org.quartz.threadPool.class=org.quartz.simpl.SimpleThreadPool org.quartz.threadPool.threadCount=10 org.quartz.jobStore.class=org.quartz.impl.jdbcjobstore.JobStoreTX org.quartz.jobStore.isClustered=true org.quartz.jobStore.driverDelegateClass=org.quartz.impl.jdbcjobstore.StdJDBCDelegate org.quartz.jobStore.tablePrefix=QRTZ_ org.quartz.jobStore.useProperties=true org.quartz.jobStore.dataSource=mysqlds org.quartz.dataSource.mysqlds.driver=com.mysql.cj.jdbc.Driver org.quartz.dataSource.mysqlds.URL=jdbc:mysql://172.17.0.2:3306/practice?characterEncoding=utf-8&connectionCollation=utf8mb4_0900_bin org.quartz.dataSource.mysqlds.user=kazuhira org.quartz.dataSource.mysqlds.password=password org.quartz.dataSource.mysqlds.maxConnections=10
パッケージング。
$ mvn package
実行。2つのインスタンスを起動することにします。
## ひとつ目 $ java -Dorg.quartz.properties=quartz-clustering.properties -jar target/app-0.0.1-SNAPSHOT.jar true true ## 2つ目 $ java -Dorg.quartz.properties=quartz-clustering.properties -jar target/app-0.0.1-SNAPSHOT.jar true false
2つ目のインスタンスは、ジョブを登録しません。最初のインスタンスが登録するからですね。
ひとつ目のインスタンスで、起動してから3つ目のジョブが起動したところでシャットダウンを開始。
[main] INFO org.littlewings.quartz.shutdown.App - scheduler start, wait for jobs to complete = [true], scheduler registered = [true] [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160589507 started. [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:43:15] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:43:30] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:43:45] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:43:45] job end [main] INFO org.littlewings.quartz.shutdown.App - shutdown start... [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160589507 shutting down. [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160589507 paused. [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt30Job - Hello from HelloAt30Job [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:44:00] job end [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt45Job - Hello from HelloAt45Job [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:44:15] job end [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160589507 shutdown complete. [main] INFO org.littlewings.quartz.shutdown.App - shutdown end
ひとつ目のインスタンスに実行ジョブが偏っていて、シャットダウンを始めたところでジョブの開始がなくなります。これは
スタンドアロンで実行していた時と同じですね。
一方で、2つ目のインスタンス側ではひとつ目のインスタンスがシャットダウンを始めた後、ジョブスケジュールに則ってジョブの
実行を継続します。
[main] INFO org.littlewings.quartz.shutdown.App - scheduler start, wait for jobs to complete = [true], scheduler registered = [false] [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160590005 started. [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:44:00] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:44:15] job start..., sleep 30sec
この後にシャットダウンを始めると、実行中のジョブの完了は待ちますがすんなり終了します。
[main] INFO org.littlewings.quartz.shutdown.App - shutdown start... [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160590005 shutting down. [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160590005 paused. [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt0Job - Hello from HelloAt0Job [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:44:30] job end [QuartzScheduler_ClusteredExampleScheduler-server1696160590005_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: detected 1 failed or restarted instances. [QuartzScheduler_ClusteredExampleScheduler-server1696160590005_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: Scanning for instance "server1696160589507"'s failed in-progress jobs. [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:44:45] job end [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696160590005 shutdown complete. [main] INFO org.littlewings.quartz.shutdown.App - shutdown end
クラスタリングしていれば、あるインスタンスがシャットダウン中であってもジョブスケジュールの引き継ぎまで行うことが
確認できました。
ちなみに、しばらく待っていると2つ目のインスタンスが他のインスタンスが終了したことを検出します。
[QuartzScheduler_ClusteredExampleScheduler-ikaruga1696160590005_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: detected 1 failed or restarted instances. [QuartzScheduler_ClusteredExampleScheduler-ikaruga1696160590005_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: Scanning for instance "server1696160589507"'s failed in-progress jobs.
続いては、ジョブの終了を待たないようにしてはどうでしょうか。
## ひとつ目 $ java -Dorg.quartz.properties=quartz-clustering.properties -jar target/app-0.0.1-SNAPSHOT.jar false true ## 2つ目 $ java -Dorg.quartz.properties=quartz-clustering.properties -jar target/app-0.0.1-SNAPSHOT.jar false false
実行時の注意点として、前述の実行例の後に続けて実行する場合は、第2引数をfalse
にする必要があります。先のアプリケーションの
実行で、ジョブスケジュールはすでに登録済みだからです。
$ java -Dorg.quartz.properties=quartz-clustering.properties -jar target/app-0.0.1-SNAPSHOT.jar false false
MySQLデータベースを作り直して実行しています。
実行結果はこちら。
ひとつ目のインスタンス。HelloAt15Job
の実行が終わり、HelloAt45Job
の実行中にシャットダウンを始めました。
[main] INFO org.littlewings.quartz.shutdown.App - scheduler start, wait for jobs to complete = [false], scheduler registered = [true] [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696161362884 started. [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:56:15] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:56:45] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:56:45] job end [main] INFO org.littlewings.quartz.shutdown.App - shutdown start... [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696161362884 shutting down. [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696161362884 paused. [ClusteredExampleScheduler_QuartzSchedulerThread] ERROR org.quartz.core.QuartzSchedulerThread - Runtime error occurred in main trigger firing loop. java.lang.IllegalStateException: JobStore is shutdown - aborting retry at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3833) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696161362884 shutdown complete. [main] INFO org.littlewings.quartz.shutdown.App - shutdown end [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - Hello from HelloAt45Job [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt45Job - [2023-10-01 20:57:15] job end [ClusteredExampleScheduler_Worker-2] ERROR org.quartz.simpl.SimpleThreadPool - Error while executing the Runnable: java.lang.IllegalStateException: JobStore is shutdown - aborting retry at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3833) at org.quartz.impl.jdbcjobstore.JobStoreSupport.triggeredJobComplete(JobStoreSupport.java:3116) at org.quartz.core.QuartzScheduler.notifyJobStoreJobComplete(QuartzScheduler.java:1786) at org.quartz.core.JobRunShell.run(JobRunShell.java:269) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
動いているには動いているのですが、シャットダウン後にJobStoreにアクセスしようとして失敗していますね…。
これは、ジョブが完了したことをJobStoreに反映しようとしているように見えます。
2つ目のインスタンス。HelloAt30Job
は、ひとつ目のインスタンスが停止する前からこちらに振り分けられて実行されていました。
[main] INFO org.littlewings.quartz.shutdown.App - scheduler start, wait for jobs to complete = [false], scheduler registered = [false] [main] INFO org.quartz.core.QuartzScheduler - Scheduler ClusteredExampleScheduler_$_server1696161363985 started. [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:56:30] job start..., sleep 30sec [QuartzScheduler_ClusteredExampleScheduler-server1696161363985_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: detected 1 failed or restarted instances. [QuartzScheduler_ClusteredExampleScheduler-server1696161363985_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: Scanning for instance "server1696161362884"'s failed in-progress jobs. [QuartzScheduler_ClusteredExampleScheduler-server1696161363985_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: ......Freed 1 acquired trigger(s). [QuartzScheduler_ClusteredExampleScheduler-server1696161363985_ClusterManager] INFO org.quartz.impl.jdbcjobstore.JobStoreTX - ClusterManager: ......Cleaned-up 1 other failed job(s). [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:57:00] job start..., sleep 30sec [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - Hello from HelloAt30Job [ClusteredExampleScheduler_Worker-1] INFO org.littlewings.quartz.shutdown.HelloAt30Job - [2023-10-01 20:57:00] job end [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:57:15] job start..., sleep 30sec
今回は、ひとつ目のインスタンスが終了したことの検知が速かったです。また、ひとつ目のインスタンスがシャットダウンした後の
HelloAt0Job
の実行から引き継いでいます。
一見問題なさそうに見えますが、こちらのインスタンスでシャットダウンを開始するとデータベースアクセスを開始して大変なことに
なります…。
[ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use! [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1621) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1535) at com.mchange.v2.c3p0.impl.NewProxyConnection.prepareStatement(NewProxyConnection.java:380) at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.invoke(AttributeRestoringConnectionInvocationHandler.java:73) at jdk.proxy2/jdk.proxy2.$Proxy4.prepareStatement(Unknown Source) at org.quartz.impl.jdbcjobstore.StdRowLockSemaphore.executeSQL(StdRowLockSemaphore.java:115) at org.quartz.impl.jdbcjobstore.DBSemaphore.obtainLock(DBSemaphore.java:113) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3857) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1550) ... 14 more [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use! [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1621) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1535) at com.mchange.v2.c3p0.impl.NewProxyConnection.prepareStatement(NewProxyConnection.java:380) at jdk.internal.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.invoke(AttributeRestoringConnectionInvocationHandler.java:73) at jdk.proxy2/jdk.proxy2.$Proxy4.prepareStatement(Unknown Source) at org.quartz.impl.jdbcjobstore.StdRowLockSemaphore.executeSQL(StdRowLockSemaphore.java:115) at org.quartz.impl.jdbcjobstore.DBSemaphore.obtainLock(DBSemaphore.java:113) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3857) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.prepareStatement(ConnectionImpl.java:1550) ... 14 more [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use! [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1816) at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:1033) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.invoke(AttributeRestoringConnectionInvocationHandler.java:73) at jdk.proxy2/jdk.proxy2.$Proxy4.rollback(Unknown Source) at org.quartz.impl.jdbcjobstore.JobStoreSupport.rollbackConnection(JobStoreSupport.java:3727) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3886) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1770) ... 13 more [ClusteredExampleScheduler_QuartzSchedulerThread] ERROR org.quartz.impl.jdbcjobstore.JobStoreTX - Couldn't rollback jdbc connection. No operations allowed after connection closed. java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1816) at com.mchange.v2.c3p0.impl.NewProxyConnection.rollback(NewProxyConnection.java:1033) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.invoke(AttributeRestoringConnectionInvocationHandler.java:73) at jdk.proxy2/jdk.proxy2.$Proxy4.rollback(Unknown Source) at org.quartz.impl.jdbcjobstore.JobStoreSupport.rollbackConnection(JobStoreSupport.java:3727) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3886) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:1770) ... 13 more [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] A PooledConnection that has already signalled a Connection error is still in use! [ClusteredExampleScheduler_QuartzSchedulerThread] WARN com.mchange.v2.c3p0.impl.NewPooledConnection - [c3p0] Another error has occurred [ java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. ] which will not be reported to listeners! java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2022) at com.mchange.v2.c3p0.impl.NewProxyConnection.setAutoCommit(NewProxyConnection.java:1059) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.restoreOriginalAtributes(AttributeRestoringConnectionInvocationHandler.java:141) at org.quartz.impl.jdbcjobstore.JobStoreSupport.cleanupConnection(JobStoreSupport.java:3677) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3896) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:1965) ... 8 more [ClusteredExampleScheduler_QuartzSchedulerThread] WARN org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler - Failed restore connection's original auto commit setting. java.sql.SQLNonTransientConnectionException: No operations allowed after connection closed. at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:111) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:98) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:90) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:64) at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:74) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:73) at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2022) at com.mchange.v2.c3p0.impl.NewProxyConnection.setAutoCommit(NewProxyConnection.java:1059) at org.quartz.impl.jdbcjobstore.AttributeRestoringConnectionInvocationHandler.restoreOriginalAtributes(AttributeRestoringConnectionInvocationHandler.java:141) at org.quartz.impl.jdbcjobstore.JobStoreSupport.cleanupConnection(JobStoreSupport.java:3677) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3896) at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3819) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) Caused by: com.mysql.cj.exceptions.ConnectionIsClosedException: No operations allowed after connection closed. at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499) at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:62) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105) at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:150) at com.mysql.cj.NativeSession.checkClosed(NativeSession.java:753) at com.mysql.cj.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:565) at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:1965) ... 8 more [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - Hello from HelloAt0Job [ClusteredExampleScheduler_Worker-2] INFO org.littlewings.quartz.shutdown.HelloAt0Job - [2023-10-01 20:57:30] job end [ClusteredExampleScheduler_Worker-2] ERROR org.quartz.simpl.SimpleThreadPool - Error while executing the Runnable: java.lang.IllegalStateException: JobStore is shutdown - aborting retry at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3833) at org.quartz.impl.jdbcjobstore.JobStoreSupport.triggeredJobComplete(JobStoreSupport.java:3116) at org.quartz.core.QuartzScheduler.notifyJobStoreJobComplete(QuartzScheduler.java:1786) at org.quartz.core.JobRunShell.run(JobRunShell.java:269) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [ClusteredExampleScheduler_QuartzSchedulerThread] ERROR org.quartz.core.QuartzSchedulerThread - Runtime error occurred in main trigger firing loop. java.lang.IllegalStateException: JobStore is shutdown - aborting retry at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3833) at org.quartz.impl.jdbcjobstore.JobStoreSupport.releaseAcquiredTrigger(JobStoreSupport.java:2940) at org.quartz.core.QuartzSchedulerThread.releaseIfScheduleChangedSignificantly(QuartzSchedulerThread.java:472) at org.quartz.core.QuartzSchedulerThread.run(QuartzSchedulerThread.java:333) [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - Hello from HelloAt15Job [ClusteredExampleScheduler_Worker-3] INFO org.littlewings.quartz.shutdown.HelloAt15Job - [2023-10-01 20:57:45] job end [ClusteredExampleScheduler_Worker-3] ERROR org.quartz.simpl.SimpleThreadPool - Error while executing the Runnable: java.lang.IllegalStateException: JobStore is shutdown - aborting retry at org.quartz.impl.jdbcjobstore.JobStoreSupport.retryExecuteInNonManagedTXLock(JobStoreSupport.java:3833) at org.quartz.impl.jdbcjobstore.JobStoreSupport.triggeredJobComplete(JobStoreSupport.java:3116) at org.quartz.core.QuartzScheduler.notifyJobStoreJobComplete(QuartzScheduler.java:1786) at org.quartz.core.JobRunShell.run(JobRunShell.java:269) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
というわけで、クラスタリングを使っている場合はScheduler#shutdown
にはtrue
を指定すべきですね。JobStoreへの反映の必要と、
Scheduler
の状態の整合性が取れなくなるようなので。
これで、確認したいことは見れたかなと思います。
オマケ:Spring Bootで試してみる
最後にオマケで、Spring Bootでも確認してみましょう。こちらはクラスタリングのみで行います。
こちらは最初からクラスタリング構成のみで確認します。
プロジェクトの作成。
$ curl -s https://start.spring.io/starter.tgz \ -d bootVersion=3.1.4 \ -d javaVersion=17 \ -d type=maven-project \ -d name=quartz-shutdown-example \ -d groupId=org.littlewings \ -d artifactId=quartz-shutdown-example \ -d version=0.0.1-SNAPSHOT \ -d packageName=org.littlewings.spring.quartz \ -d dependencies=quartz,jdbc,mysql \ -d baseDir=quartz-shutdown-example | tar zxvf -
ディレクトリ内に移動。
$ cd quartz-shutdown-example
自動生成されたソースコードは削除。
$ rm src/main/java/org/littlewings/spring/quartz/QuartzShutdownExampleApplication.java src/test/java/org/littlewings/spring/quartz/QuartzShutdownExampleApplicationTests.java
ログ設定はSpring BootのLogbackのものになるので、ジョブの内容を少し簡素にしました。
src/main/java/org/littlewings/spring/quartz/HelloAt0Job.java
package org.littlewings.spring.quartz; import org.quartz.Job; import org.quartz.JobExecutionContext; import org.quartz.JobExecutionException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import java.time.format.DateTimeFormatter; import java.util.concurrent.TimeUnit; public class HelloAt0Job implements Job { Logger logger = LoggerFactory.getLogger(HelloAt0Job.class); @Override public void execute(JobExecutionContext jobExecutionContext) throws JobExecutionException { logger.info("job start..., sleep 30sec"); try { TimeUnit.SECONDS.sleep(30L); } catch (InterruptedException e) { } logger.info("Hello from {}", getClass().getSimpleName()); logger.info("job end"); } }
その他のジョブの中身は同じなので、割愛します。
main
メソッドとジョブの登録。
src/main/java/org/littlewings/spring/quartz/App.java
package org.littlewings.spring.quartz; import org.quartz.JobDetail; import org.springframework.boot.SpringApplication; import org.springframework.boot.autoconfigure.SpringBootApplication; import org.springframework.context.annotation.Bean; import org.springframework.scheduling.quartz.CronTriggerFactoryBean; import org.springframework.scheduling.quartz.JobDetailFactoryBean; @SpringBootApplication public class App { public static void main(String... args) { SpringApplication.run(App.class, args); } @Bean("helloAt0Job") public JobDetailFactoryBean helloAt0JobDetailFactoryBean() { JobDetailFactoryBean jobDetailFactoryBean = new JobDetailFactoryBean(); jobDetailFactoryBean.setName("hello-at0-job"); jobDetailFactoryBean.setGroup("job-group1"); jobDetailFactoryBean.setJobClass(HelloAt0Job.class); jobDetailFactoryBean.setDurability(true); return jobDetailFactoryBean; } @Bean public CronTriggerFactoryBean helloAt0CronTriggerFactoryBean(JobDetail helloAt0Job) { CronTriggerFactoryBean cronTriggerFactoryBean = new CronTriggerFactoryBean(); cronTriggerFactoryBean.setName("hello-at0-trigger"); cronTriggerFactoryBean.setGroup("trigger-group1"); cronTriggerFactoryBean.setJobDetail(helloAt0Job); cronTriggerFactoryBean.setCronExpression("0 * * * * ?"); return cronTriggerFactoryBean; } @Bean("helloAt15Job") public JobDetailFactoryBean helloAt15JobDetailFactoryBean() { JobDetailFactoryBean jobDetailFactoryBean = new JobDetailFactoryBean(); jobDetailFactoryBean.setName("hello-at15-job"); jobDetailFactoryBean.setGroup("job-group1"); jobDetailFactoryBean.setJobClass(HelloAt15Job.class); jobDetailFactoryBean.setDurability(true); return jobDetailFactoryBean; } @Bean public CronTriggerFactoryBean helloAt15CronTriggerFactoryBean(JobDetail helloAt15Job) { CronTriggerFactoryBean cronTriggerFactoryBean = new CronTriggerFactoryBean(); cronTriggerFactoryBean.setName("hello-at15-trigger"); cronTriggerFactoryBean.setGroup("trigger-group1"); cronTriggerFactoryBean.setJobDetail(helloAt15Job); cronTriggerFactoryBean.setCronExpression("15 * * * * ?"); return cronTriggerFactoryBean; } @Bean("helloAt30Job") public JobDetailFactoryBean helloAt30JobDetailFactoryBean() { JobDetailFactoryBean jobDetailFactoryBean = new JobDetailFactoryBean(); jobDetailFactoryBean.setName("hello-at30-job"); jobDetailFactoryBean.setGroup("job-group1"); jobDetailFactoryBean.setJobClass(HelloAt30Job.class); jobDetailFactoryBean.setDurability(true); return jobDetailFactoryBean; } @Bean public CronTriggerFactoryBean helloAt30CronTriggerFactoryBean(JobDetail helloAt30Job) { CronTriggerFactoryBean cronTriggerFactoryBean = new CronTriggerFactoryBean(); cronTriggerFactoryBean.setName("hello-at30-trigger"); cronTriggerFactoryBean.setGroup("trigger-group1"); cronTriggerFactoryBean.setJobDetail(helloAt30Job); cronTriggerFactoryBean.setCronExpression("30 * * * * ?"); return cronTriggerFactoryBean; } @Bean("helloAt45Job") public JobDetailFactoryBean helloAt45JobDetailFactoryBean() { JobDetailFactoryBean jobDetailFactoryBean = new JobDetailFactoryBean(); jobDetailFactoryBean.setName("hello-at45-job"); jobDetailFactoryBean.setGroup("job-group1"); jobDetailFactoryBean.setJobClass(HelloAt45Job.class); jobDetailFactoryBean.setDurability(true); return jobDetailFactoryBean; } @Bean public CronTriggerFactoryBean helloAt45CronTriggerFactoryBean(JobDetail helloAt45Job) { CronTriggerFactoryBean cronTriggerFactoryBean = new CronTriggerFactoryBean(); cronTriggerFactoryBean.setName("hello-at45-trigger"); cronTriggerFactoryBean.setGroup("trigger-group1"); cronTriggerFactoryBean.setJobDetail(helloAt45Job); cronTriggerFactoryBean.setCronExpression("45 * * * * ?"); return cronTriggerFactoryBean; } }
Spring Bootの場合、Quartzの設定はapplication.properties
で設定できます。
src/main/resources/application.properties
spring.datasource.url=jdbc:mysql://172.17.0.2:3306/practice?characterEncoding=utf-8&connectionCollation=utf8mb4_0900_bin spring.datasource.username=kazuhira spring.datasource.password=password spring.quartz.job-store-type=jdbc spring.quartz.properties.org.quartz.jobStore.isClustered=true spring.quartz.properties.org.quartz.jobStore.useProperties=true spring.quartz.jdbc.initialize-schema=never spring.quartz.wait-for-jobs-to-complete-on-shutdown=true
Quartzが使うデータベースは、spring.datasource.〜
のものになります。
JobStoreはjdbc
にして、クラスタリングも有効化。Quartzのテーブルは先に作成済みとします。
spring.quartz.job-store-type=jdbc spring.quartz.properties.org.quartz.jobStore.isClustered=true spring.quartz.properties.org.quartz.jobStore.useProperties=true spring.quartz.jdbc.initialize-schema=never
Scheduler#shutdown
の設定は、spring.quartz.wait-for-jobs-to-complete-on-shutdown
で設定しますが、デフォルト値はfalse
です。
spring.quartz.wait-for-jobs-to-complete-on-shutdown
今回はtrue
にしておきます。
spring.quartz.wait-for-jobs-to-complete-on-shutdown=true
では、パッケージングして
$ mvn package
起動。
## ひとつ目 $ java -jar target/quartz-shutdown-example-0.0.1-SNAPSHOT.jar ## 2つ目 $ java -jar target/quartz-shutdown-example-0.0.1-SNAPSHOT.jar
ひとつ目のインスタンスで、HelloAt15Job
が実行終了、HelloAt30Job
が実行中のところでCtrl-cでシャットダウン。
なお、HelloAt45Job
は2つ目のインスタンスで起動しました。
2023-10-01T21:55:15.056+09:00 INFO 30881 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt15Job : job start..., sleep 30sec 2023-10-01T21:55:30.046+09:00 INFO 30881 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt30Job : job start..., sleep 30sec 2023-10-01T21:55:45.057+09:00 INFO 30881 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt15Job : Hello from HelloAt15Job 2023-10-01T21:55:45.058+09:00 INFO 30881 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt15Job : job end ^C2023-10-01T21:55:49.124+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused. 2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] o.s.s.quartz.SchedulerFactoryBean : Shutting down Quartz Scheduler 2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutting down. 2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused.
ジョブの完了を待ってから終了するようになっています。
2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] o.s.s.quartz.SchedulerFactoryBean : Shutting down Quartz Scheduler 2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutting down. 2023-10-01T21:55:49.125+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused. 2023-10-01T21:56:00.047+09:00 INFO 30881 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt30Job : Hello from HelloAt30Job 2023-10-01T21:56:00.047+09:00 INFO 30881 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt30Job : job end 2023-10-01T21:56:00.078+09:00 INFO 30881 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutdown complete. 2023-10-01T21:56:00.079+09:00 INFO 30881 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated... 2023-10-01T21:56:00.090+09:00 INFO 30881 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2つ目のインスタンスの様子。ひとつ目のインスタンスがシャットダウン中に起動タイミングを迎えたHelloAt0Job
の実行を引き継いでは
いるのですが、開始タイミングがちょっと遅れてますね…。
2023-10-01T21:55:45.057+09:00 INFO 30923 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt45Job : job start..., sleep 30sec 2023-10-01T21:56:15.046+09:00 INFO 30923 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt15Job : job start..., sleep 30sec 2023-10-01T21:56:15.058+09:00 INFO 30923 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt45Job : Hello from HelloAt45Job 2023-10-01T21:56:15.058+09:00 INFO 30923 --- [eduler_Worker-1] o.l.spring.quartz.HelloAt45Job : job end 2023-10-01T21:56:15.121+09:00 INFO 30923 --- [eduler_Worker-3] o.littlewings.spring.quartz.HelloAt0Job : job start..., sleep 30sec
その後、終了。
2023-10-01T21:56:28.069+09:00 INFO 30923 --- [ionShutdownHook] o.s.s.quartz.SchedulerFactoryBean : Shutting down Quartz Scheduler 2023-10-01T21:56:28.069+09:00 INFO 30923 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutting down. 2023-10-01T21:56:28.069+09:00 INFO 30923 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED paused. 2023-10-01T21:56:45.047+09:00 INFO 30923 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt15Job : Hello from HelloAt15Job 2023-10-01T21:56:45.048+09:00 INFO 30923 --- [eduler_Worker-2] o.l.spring.quartz.HelloAt15Job : job end 2023-10-01T21:56:45.122+09:00 INFO 30923 --- [eduler_Worker-3] o.littlewings.spring.quartz.HelloAt0Job : Hello from HelloAt0Job 2023-10-01T21:56:45.122+09:00 INFO 30923 --- [eduler_Worker-3] o.littlewings.spring.quartz.HelloAt0Job : job end 2023-10-01T21:56:45.153+09:00 INFO 30923 --- [ionShutdownHook] org.quartz.core.QuartzScheduler : Scheduler quartzScheduler_$_NON_CLUSTERED shutdown complete. 2023-10-01T21:56:45.155+09:00 INFO 30923 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated... 2023-10-01T21:56:45.166+09:00 INFO 30923 --- [ionShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
こちらもジョブの実行を待ってからの終了になりました。
ちょっとジョブの実行タイミングはブレましたが、まあいいでしょう…。
spring.quartz.wait-for-jobs-to-complete-on-shutdown
の反映先は、こちら。
SchedulerFactoryBean#setWaitForJobsToCompleteOnShutdown)
そして、Bean破棄のタイミングで呼び出されるScheduler#shutdown
の引数に使われます。
おわりに
QuartzのScheduler#shutdown
を実行した時の、実行中のジョブの扱いを確認してみました。
基本的には、Scheduler#shutdown
はtrue
にするのが良さそうなのですが、どうしてこれデフォルトでtrue
ではないんでしょうね…?