長時間タスクの問題¶
概要¶
ICE CoreはNode.js上で動作します。Node.jsの実行基盤は、非同期APIを用いて記述されたアプリケーションロジックを実行時間の短い複数のタスクに分割し、そのタスクをスケジューリングすることにより効率的に並列処理を実行します。
しかしながら、あるロジックが非同期APIを使わず同期処理的に記述されると、実行基盤はそのロジックのタスクのみを長時間実行することになります。その場合、そのロジック自体の性能や機能に影響はありませんが、並行して動作する周期的処理が想定した時刻よりも大幅にずれるなどの影響がある場合があります。
そのような長時間タスクをICE Core実行中に検出し、ログに出力をする機能を提供します。
機能¶
以下2つの機能を提供します。
- 長時間タスクの検出
- タスク実行時間統計情報出力
最初にタスク実行時間統計情報出力機能を用いて全体の傾向をつかみ、改善する必要のあるタスクを長時間タスク検出機能で実行タイミングやコードの場所を特定し、修正することを想定しています。
長時間タスク検出機能¶
各タスクの実行時間を測定し、実行時間がLongTaskDetector.alert.thresholdを越えたものをINFOログに出力します。
出力内容は以下です。
- 実行時間(ミリ秒)
- タイプ(Timeout, Immediate, TickObjectなど。詳しくはNode.jsのAsync Hooks APIのドキュメントを参照してください)
- タスク生成時の実行スタック(LongTaskDetector.alert.holdCallStackがtrueの場合のみ)
タスク生成時の実行スタックは長時間タスクの特定に非常に有効ですが、性能に影響がある場合があるため既定で無効になっています。
あるタスクが長時間タスクかどうかの判定はそのタスクが終了した後に行われます。
長時間タスクを検出した瞬間にログ出力をするのではなく、LongTaskDetector.alert.intervalで指定した周期ごとにログ出力を行います。
タスク実行時間統計情報出力¶
全てのタスクの実行時間を測定し、LongTaskDetector.statistics.thresholdを越えたものをカウントし、ICE Coreの終了時にログ出力をします。以下が出力例です。
executionTime,count
0,997389
1,284387
2,6684
3,8686
4,418
...
設定¶
これら機能を利用するには、core_config.jsonのルートにLongTaskDetector要素を以下のように追加します。
{
"LongTaskDetector": {
"alert": {
"enabled": true,
"threshold": 1000,
"interval": 10000,
"holdCallStack": false
},
"statistics": {
"enabled": true,
"threshold": 0
}
},
...
}
それぞれのパラメータの説明は以下の通りです。
パラメータ名 | 説明 | 既定値 |
---|---|---|
LongTaskDetector.alert.enabled | 長時間タスク検出機能を有効にするかどうか | true |
LongTaskDetector.alert.threshold | 長時間タスクを検出する閾値をミリ秒で指定 | 1000 |
LongTaskDetector.alert.interval | 長時間タスク検出のログ出力の間隔をミリ秒で指定する | 10000 |
LongTaskDetector.alert.holdCallStack | 長時間タスク検出時にタスクの初期化のスタックトレースを出力するかどうか | false |
LongTaskDetector.statistics.enabled | タスク実行時間統計情報出力機能を有効にするかどうか | true |
LongTaskDetector.statistics.threshold | 統計情報を記録する実行時間をミリ秒で指定 | 0 |
注意事項・警告メッセージについて¶
「長時間タスクの検出」および「タスク実行時間統計情報出力」はNode.jsの実験的機能を利用しています。開発・評価時に利用し、運用環境では有効化しないでください。有効化していると、以下の警告メッセージがログに出力されます。
LongTaskDetector is enabled. DO NOT USE THIS IN PRODUCTION ENVIRONMENT