New Relic Flex のタイムアウト設定

New Relic Flex (nri-flex) のタイムアウト設定には複数の種類があり、それぞれフォーマットや設定箇所が異なります。
本ブログポストでは、実機での検証結果をもとに、各設定の意味やタイムアウト時の挙動、エラー出力について解説します。

nri-flex について

nri-flex は New Relic Infrastructure エージェントのオンホストインテグレーションの１つで、簡単に言えば、ユーザーが設定したコマンドやスクリプトの結果をイベントとして、送信する機能です。

同機能は、New Relic Infrastructure エージェントにバンドルされているため、エージェントの導入 (追加のインストールなし) のみで、利用いただけます。 nri-flex 用の設定ファイルにコマンドなどを記述すると、インフラエージェントが定期的にコマンドを実行してくれます。

ドキュメントには、設定例などもございますので、デフォルトの収集項目以外で収集したいデータがある場合はご利用ください。

参考

nri-flex のタイムアウトは大別すると 2種類

nri-flex ではインフラエージェントが flex config 内のインターバル (interval) 設定にしたがって、flex プロセスを定期的に実行します。
インフラエージェントによって実行された flex プロセスは、記載されたコマンドを順番に実行し、最後まで実行し終えたあとに、取得した結果 (データ) を (インフラエージェント経由で) 送信します。

インターバルごとに呼び出される flex の実行プロセス (コマンド実行、エラーハンドリング、結果データの送信前プロセス) に関するタイムアウト設定と (apis 内で設定された) 各コマンドの実行に関するタイムアウト設定の 2種類が存在します。

ここでは両者を区別するために、便宜的にコマンドタイムアウトとプロセスタイムアウトと呼び分けます。
コマンドがコマンドタイムアウト内に完了しない場合、該当コマンドが強制終了します、次のコマンドがある場合は、次のコマンド実行されます。
この場合、コマンドが時間内 (コマンドタイムアウト内) に完了しなかった旨 (context deadline exceeded) が flex のイベントデータとして送信されます。
また、コマンドタイムアウトはデフォルトタイムアウトと各コマンドごとに設定が可能です。

コマンドタイムアウトを明示的に指定しなかった場合は、10秒 (デフォルト) となります。

一方で、プロセスがプロセスタイムアウト内に完了しなかった場合、プロセス自体が強制終了します。このとき flex のイベントデータ自体は送信されず、インフラエージェントのログに flex プロセスが時間内 (プロセスタイムアウト内) に完了しなかったエラー (HeartBeat timeout exceeded after {{プロセスタイムアウト}} seconds) が記録されます。 (また、次のインターバルタイミングでは再度、flex プロセスが実行されます。)

flex プロセスでは、全コマンドの終了後にデータを送信しようとするため、すべてのコマンドがプロセスタイムアウト内に終了していないと、(実行が終了した) いずれのコマンドの結果も送信されません。

プロセスタイムアウトを明示的に指定しなかった場合、デフォルトの 2分が採用されます。

タイムアウトを設定した記載例

integrations:
  - name: nri-flex
    timeout: 1m # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 15000 # コマンドデフォルトタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 25 && echo "pattern-1:25"
              timeout: 30000  #コマンドタイムアウト
              # doesNotTimeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"
            - run: sleep 10 && echo "pattern-2:10"
              # alsoDoesNotTimeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"
            - run: sleep 20 && echo "pattern-3:20"
              # timeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"

上記では、timeout に関する設定が 3箇所でてきますが、それぞれ意味が異なります。
3行目の timeout (name: nri-flex の直下) は、プロセスタイムアウトを意味します。
プロセスタイムアウトはナノ秒単位での指定となるため、60秒の場合は 60000000000 とします。しかし、読みにくいので、通常は 60s, 2m など時間の単位をつけて設定します。
この設定例では 1分 (1m) としています。
記載しなかった場合は、デフォルトの 2m (2分) となります。
また、最小値は 100ミリ秒 (100000000 ナノ秒) で、100ミリ秒未満の値を設定すると最小値の 100ミリ秒に設定されてしまいます。

ミリ秒指定と間違えて、timeout: 10000 と設定してしまうと、実際は 10マイクロ秒という入力であるため、100ミリ秒に設定されます。

level=warning
msg="timeout is too low (did you forget to append the time unit suffix?). Using minimum allowed value"
component=integrations.Definition minimum_timeout=100ms timeout="10µs"

9行目の timeout (apis > name: linuxTimeout の直下) は、コマンドのデフォルトタイムアウトを意味します。
コマンドタイムアウトはミリ秒単位で入力します。
この例では 15秒 (15000ミリ秒) が指定されています。
各コマンドでタイムアウトの指定がない場合は、ここで指定されたコマンドのデフォルトタイムアウトが採用されます。

また、デフォルトタイムアウトを記載しなかった場合は、デフォルトの 10秒 (10000ミリ秒) が採用されます。

この flex 設定 (commands) では 3つのコマンドが設定されています。

1つ目は pattern1 (doesNotTimeout) で sleep 25 秒を実行しますが、13行目にこのコマンド用の timeout が 30秒と設定されています。
したがって、このコマンドのタイムアウトは 30秒となり、(sleep 25 では) コマンドタイムアウトはしません。

2つ目は pattern2 (alsoDoesNotTimeout) で sleep 10 秒を実行するコマンドが指定されています。
pattern1 とは異なり、このコマンド用の timeout は設定されていないので、コマンドのデフォルトタイムアウトの 15秒と設定されています。
したがって、このコマンド (sleep 10) もタイムアウトせず、実行されます。

3つ目は pattern3 (timeout) で sleep 20 秒を実行するコマンドが指定されています。
pattern2 同様、このコマンド用の timeout は設定されていないので、コマンドのデフォルトタイムアウトの 15秒と設定されています。
したがって、このコマンド (sleep 20) はタイムアウトします。

3つのコマンドの実行時間はそれぞれ 25秒, 10秒, 15秒 (タイムアウトで終了させられる) であるため、およそ 50秒で終了します。
合計時間の見込みは、プロセスタイムアウトの 1分未満であるため、プロセスは正常に完了し、データは送信されます。

NRQL の出力確認 (pattern 3 はコマンドタイムアウトエラーと記録される)

プロセスタイムアウトする例

integrations:
  - name: nri-flex
    timeout: 1m # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 15000 # コマンドデフォルトタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 25 && echo "pattern-1:25"
              timeout: 30000 # コマンドタイムアウト
              # doesNotTimeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"
            - run: sleep 10 && echo "pattern-2:10"
              # alsoDoesNotTimeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"
            - run: sleep 20 && echo "pattern-3:20"
              # timeout
              split: horizontal
              set_header: [name, value]
              split_by: ":"
            - run: sleep 15 && echo "pattern-4:15"
              # alsoDoesNotTimeout
              timeout: 30000 # コマンドタイムアウト
              split: horizontal
              set_header: [name, value]
              split_by: ":"

先の例とほぼ一緒ですが、4つ目のコマンド sleep 15秒 (コマンドタイムアウト 30秒) を追加しました。
4つ目のコマンドは単体でみるとタイムアウトはしませんが、4つのコマンド全体でみると
25秒、10秒、15秒、15秒で通常で実行すると 65秒かかることになります。

この場合、プロセスタイムアウトの 1分を超過するため、すべてのコマンドが終了する前に、プロセスが強制的に終了させられてしまいます。

インフラエージェントログに、下記のようなエラー出力が記録され、いずれのコマンドの結果も送信されません。

level=warning
msg="HeartBeat timeout exceeded after 60.000000 seconds"
component=integrations.runner.Runner
integration_name=nri-flex runner_uid=xxx

level=debug
msg="Integration has been interrupted. Finishing."
component=integrations.runner.Runner
integration_name=nri-flex runner_uid=xxx

記載例とその挙動

複数の apis 設定を記載した場合の挙動

次のような apis に 3つの設定を記載した例を試していみます。

integrations:
  - name: nri-flex
    timeout: 50s # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeoutA
          timeout: 15000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-A:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"
        - name: linuxTimeoutB
          timeout: 30000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-B:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"
        - name: linuxTimeoutB # 2つ目と同じ名前
         # デフォルトコマンドタイムアウト記載なし
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-C:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"

設定内容:
プロセスタイムアウトが 50秒、
1つ目は linuxTimeoutA ではデフォルトコマンドタイムアウトが 15秒、
2つ目は linuxTimeoutB ではデフォルトコマンドタイムアウトが 30秒、
3つ目は 2つ目と同じ名前で linuxTimeoutB で、デフォルトコマンドタイムアウトの記載なし、
で、いずれもコマンドは sleep 20 (スリープ 20秒) のみが設定されています。

結論:
1つ目の linuxTimeoutA のコマンドタイムアウトは 15秒であるため、コマンドタイムアウトが発生します。
2つ目の linuxTimeoutB のコマンドタイムアウトは 30秒であるため、タイムアウトせずにコマンドが実行されます。
3つ目は 2つ目と同じ名前ですが別の入力とみなされ、コマンドタイムアウトは (デフォルトの) 10秒が採用され、コマンドタイムアウトとなります。
しかし、この記載方法の場合、コマンドは順番に実行されるため、15秒、30秒、10秒で、トータルでは、55秒かかるため、実際は 3つ目のコマンド実行中にプロセスタイムアウトで、プロセスが終了させられます。
(プロセスタイムアウトが発生したため、データは送信されません)

同一設定ファイルに複数の flex 設定を記載した場合の挙動

次に、同一ファイルに複数の nri-flex を設定した場合の挙動を確認してみます。

integrations:
  # flex setting 1
  - name: nri-flex
    timeout: 15s # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 30000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-1:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"
  # flex setting 2
  - name: nri-flex
    timeout: 1m # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 30000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-2:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"

この例では同一ファイルに 2つの flex 設定がまとめて記載されています。
nri-flex setting 1 はプロセスタイムアウトは 15秒で、コマンドタイムアウトは 30秒、コマンドは sleep 20 (スリープ 20秒)、
nri-flex setting 2 はプロセスタイムアウトは 1分で、コマンドタイムアウトは 30秒、コマンドは sleep 20 (スリープ 20秒)、となっており、どちらもコマンドタイムアウトは起こらないと予想できます。
また、いずれも config name は同一で example としており、プロセスタイムアウトはどのスコープに適用されるのか一見すると不明瞭です。

実際に実行してみると、
nri-flex setting 1 と nri-flex setting 2 は別プロセスとして、並列に実行されました。
結果として、nri-flex setting 1 ではプロセスタイムアウトが発生し、nri-flex setting 2 ではプロセスタイムアウトは発生しませんでした。
nri-flex setting 1 のデータは送信されず、nri-flex setting 2 のデータは送信されました。

config 名が同じであっても、別プロセス、別スコープとして認識されるようです。

複数の設定ファイルに flex 設定を記載した場合の挙動

最後に複数の flex 設定ファイルに同一 config 名の nri-flex を設定した場合の挙動を確認してみます。
先の内容をそれぞれ別のファイルに記載しました。

flex-setting-1.yml

integrations:
  - name: nri-flex
    timeout: 15s # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 30000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-1:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"

flex-setting-2.yml

integrations:
  - name: nri-flex
    timeout: 1m # プロセスタイムアウト
    interval: 2m
    config:
      name: example
      apis:
        - name: linuxTimeout
          timeout: 30000 # デフォルトコマンドタイムアウト
          shell: /bin/sh
          commands:
            - run: sleep 20 && echo "pattern-2:20"
              split: horizontal
              set_header: [name, value]
              split_by: ":"

flex-setting-1.yml ではプロセスタイムアウトは 15秒で、コマンドタイムアウトは 30秒、コマンドは sleep 20 (スリープ 20秒)、
flex-setting-2.yml はプロセスタイムアウトは 1分で、コマンドタイムアウトは 30秒、コマンドは sleep 20 (スリープ 20秒)、となっており、どちらもコマンドタイムアウトは起こらないと予想できます。
また、いずれも config name は同一で example としており、プロセスタイムアウトが別ファイルの場合は、適用されるのかという点が注目点です。

結果は、予想通りですが、
flex-setting-1.yml と flex-setting-2.yml 設定はそれぞれ別プロセスとして、並列に実行されました。
flex-setting-1.yml ではプロセスタイムアウトが発生し、flex-setting-2.yml ではプロセスタイムアウトは発生しませんでした。

まとめ

github の nri-flex のコマンドパートの解説には、コマンドタイムアウトに関する記述はありますが、プロセスタイムアウトに関する記述はないようです。

nri-flex コマンドの実行自体は、Infrastructure エージェントが担うため、インターバルや実行プロセスのタイムアウトは Infrastructure エージェント側で認識される項目となるようです。
デバッグなどで nri-flex を手動実行した場合は、プロセスのタイムアウトは考慮されないため、手動では実行できるが、Infrastructure エージェント経由だと (プロセスタイムアウトで) 実行できないということも発生する可能性があります。
設定後は Infrastructure エージェント経由でデータが取得できているか、までをご確認ください。