こんにちは、アプリケーションエンジニアの難波です。

BraveridgeのIoTサービスはSpringBootをベースにWebアプリケーションを構築しています。
Webアプリではさまざまな定期実行処理を実装することがよくあります。
(IoTデバイスの死活チェック、外部webサービス(e.g. 気象庁)からデータ取得など、、、)

これらの処理が正常に実行できているかどうかをプロセス、スレッド、タスクのそれぞれでモニタリングする必要があります。

プロセスは、例えばSpringBootのMicrometerでJVMのmetricsを出力すれば、死活監視できそうです。
タスクは、例えば、更新するデータの最終更新日時をチェックすることで、死活監視できそうです。

それでは、スレッドの監視はどうすれば良いでしょうか?
今回は、弊社でおこなっている定期実行処理のスレッドの死活監視方法を紹介します。

モニタリングの目的

プロセスとタスクのモニタリングができていれば、スレッドの監視は必要ないかもしれません。

もちろん、IoTサービスのローンチ時はプロセスとタスクのモニタリング設定を完璧にできます。
ですが、定期実行するタスクは機能追加とともに増える可能性があります。
人間なのでモニタリング設定を忘れることもあります。

そこで、スレッドのモニタリングも行うことで、定期実行処理の死活監視をカバーします。

技術スタック

  • Kotlin
  • SpringBoot2
  • AWS

定期実行処理のスレッドのモニタリング

定期実行処理の実装

SpringBootで定期実行処理を実装する方法はいくつかありますが、手軽な実装として @Scheduled をよく使用しています。
参考リンク


@Scheduled(fixedDelay = 5 * 60 * 1000)  
fun task1() {
    ....
}




@Scheduled で実行される処理は"scheduling-N"という名前のスレッドで実行されます。
デフォルトでは N は 1 だけで"scheduling-1"という名前のスレッドのみ生成されますが、スレッドプールサイズを変更するとことでscheduling-2、 scheduling-3 という風に実行スレッドを増やすことができます。


spring:
  task:
    scheduling:
      pool:
        size: 2



弊社のIoTサービスでは、2 または 3 に設定することが多いです。

モニタリングの方法

具体的なモニタリング方法として以下が考えられます。

1. @Scheduled をつけた関数内で最後に完了メッセージをログ出力する


@Scheduled(fixedDelay = 5 * 60 * 1000)  
fun task1() {
    ....
    logger.info { "finished task1" }
}



AWS CloudWatch にログを出力して、メトリクスフィルターを設定して"finish task1"をカウントする。

デメリット:
 処理するタスク(関数)を増やすたびに、CloudWatchでメトリクスフィルターの設定を追加する必要がある。忘れがち。

2. AWS CloudWatch にログを出力して、メトリクスフィルターを設定して"scheduling-1"をカウントする


メリット:
 処理するタスク(関数)を増やしても、CloudWatchの設定を変更しなくて良い。

デメリット:
 スレッドプールサイズを変更したときに、CloudWatchのメトリクスフィルターの設定を追加する必要がある。忘れがち。
 ※各スレッドごとに正常動作しているかチェックする必要がある

3. 実行スレッドの状態をMicrometerのメトリクスとして出力する

SpringBootではMeterRegistryを実装することで、Micrometerのメトリクスとして登録することができます。

メリット:
 処理するタスク(関数)が増えても、スレッドプールサイズを変更しても、MeterRegistryを実装すれば動的に対応できる。

デメリット
 独自のMeterRegistryを実装する必要がある。

プログラムコードで実装すれば、ソースコードとしてリポジトリで管理できるので、上記3の方法でモニタリングを実現します。
※加えて、AWS のコンソールで設定するよりコードを書く方が楽しいので、私にとってこのデメリットは逆にメリットになります。


スレッドの状態を調査する

さて、メトリクスとして出力する実行スレッドの状態ですが、正常に定期処理が実行されている時、どのように状態が変化しているのでしょうか?

​調査のため、actuator の threaddump を観察してみます。


management:
  server:
    port: 8081
  endpoints:
    web:
      exposure:
        include: threaddump



http://localhost:8081/actuator/threaddump にアクセスすると "blockedCount" と "waitedCount" が少しずつ増加していることがわかります。

特に "waitedCount" が程よいスピードで増加しているので、この "waitedCount" の一定時間ごとの差分をメトリクスとして出力することで、モニタリングできそうです。

waitedCount

ここでthreadのwaitedCountですが、以下のような値です。

スレッドがWAITINGまたはTIMED_WAITING状態であった合計回数。

定期的にタスクが実行されていればwaitedCountが増加するので、定期実行処理のモニタリングに直感的に使用できそうです。

MeterRegistryを実装する

以下に、実装したMeterRegistryを記載します。


@Configuration
class AppConfig {
    @Value("\${spring.task.scheduling.pool.size}")
    private val taskSchedulingPoolSize: Int = 1

    @Bean
    fun threadDumpMeterBinder(): MeterBinder =
        MeterBinder {
            TaskSchedulerThreadMeter(it, ManagementFactory.getThreadMXBean())
                .register(taskSchedulerThreadPoolSize)
        }
}



class TaskSchedulerThreadMeter(
    private val registry: MeterRegistry,
    private val threadMXBean: ThreadMXBean
) {
    companion object {
        private const val meterPrefix = "taskScheduler.thread"
        private const val tagKey = "threadId"
    }

    private val previousWaitedCountMap: MutableMap = mutableMapOf()

    fun register(threadPoolSize: Int = 1) {
        (1..threadPoolSize).forEach { id ->
            previousWaitedCountMap[id] = 0

            val tags = Tags.of(tagKey, "$id")
            registry.gauge("$meterPrefix.waitedCount", tags, 0) {
                getAndStoreWaitedCount(id).toDouble()
            }
        }
    }

    privat fun getAndStoreWaitedCount(id: Int): Long {
        val currentWaitedCount = getTaskSchedulerThread(id)?.waitedCount ?: 0
        val diff = currentWaitedCount - previousWaitedCountMap.getOrDefault(id, 0)
        previousWaitedCountMap[id] = currentWaitedCount
        return diff
    }

    private fun getTaskSchedulerThread(id: Int): ThreadInfo? =
        threadMXBean.dumpAllThreads(true, true)
            .firstOrNull { it.threadName == "scheduling-$id" }
}




※waitedCountの差分をmetricsとして出力しています。

application.yml で TaskSchedulerThreadMeterクラスで登録した taskScheduler をカスタムメトリクスとして有効にします


management:
  metrics:
    use-global-registry: false
    enable:
      all: false
      taskScheduler: true



Micrometerのメトリクスを micrometer-registry-cloudwatch を使用してAWS CloudWtachに送信します。
定期的にwaitedCount(差分)が出力されているのが確認できます。



このtaskScheduler.thread.waitedCountメトリクスをもとにCloudWatchでアラームを作成することで、スレッドが停止した場合に通知することができます。

 

まとめ

SpringBoot2の定期実行処理のモニタリング方法について解説しました。
スレッドのメトリクスを監視することで、アプリケーションの機能追加に依存しないモニタリングを行うことができました。
これで安心して眠れますね。

SNS SHARE