Usual Software Engineer

よくあるソフトウェアエンジニアのブログ

Nomad の restart と reschedule の挙動を確かめる

9 月のブログさぼったので 9 月分として書きます。ネタは Nomad についでです。

Nomad の job には restartreschedule の設定があり、それらで task 失敗時の挙動を変化させることができます。 ただドキュメントを一見してもすぐには理解できないので挙動を確かめてみました。

公式ドキュメントは以下です。

挙動を確かめたサンプルリポジトリはこちらです。

github.com

restart Stanza と reschedule Stanza

さて、 restart,reschedule を特に自分で設定しなかった場合、つまりデフォルト値での挙動を見ていきます。

まず前提として job には 3 種類あり*1、その種類により restart,reschedule のデフォルト値は変わります。 また、 restart は task 失敗時の挙動を定義するもので、 reschedulerestart の結果が failed だった場合に更なる挙動を定義するものになります。 簡単に言うと、 restart で数回リトライしてダメなら reschedule で時間を空けて別のノード上で再リトライする、みたいな挙動を設定できます。 余談ですが restart,reschedule どちらも task の group に対して設定されるので、別々の設定をしたい場合は group が別々である必要がありますね。

では job の type ごとにそれぞれ説明します。

type service

service job は基本的に常駐させたい job に使用します。 web サーバであったり log 収集プロセスであったり、まあ基本この type を使用するでしょう。 デフォルト値は以下になります。

https://github.com/innossh/nomad-example/blob/v0.0.3/jobs/default-service.nomad#L8-L19

    restart {
      interval = "1m"
      attempts = 2
      delay    = "15s"
      mode     = "fail"
    }
    reschedule {
      delay          = "30s"
      delay_function = "exponential"
      max_delay      = "1h"
      unlimited      = true
    }

これは以下のような設定を意味しています。

  • restart 設定により 1 分の間(interval)に最大 2 回(attempts) リトライする
    • 各リトライ前に 15 秒の遅れ(delay)をもたせる
      • 正確には設定値の最大 25 % が上乗せされた遅れ*2
    • mode fail のためリトライを失敗し続けた場合 status は failed となる
  • status が failed の場合 reschedule 設定により30 秒の遅れ(delay)の後 job の実行を上記の restart 設定で再計画する
    • 再計画の遅れの時間を最大 1 時間(max_delay)まで指数関数的に増やしつつ、 回数制限なく(unlimited)再計画する

実際の動きは後述しますのでいったんこんな説明で。

type batch

batch job は常駐しない job に使用します。文字通りバッチ実行などです。 デフォルト値は以下になります。

https://github.com/innossh/nomad-example/blob/v0.0.3/jobs/default-batch.nomad#L8-L20

    restart {
      attempts = 15
      delay    = "15s"
      interval = "168h"
      mode     = "fail"
    }
    reschedule {
      attempts       = 1
      interval       = "24h"
      unlimited      = false
      delay          = "5s"
      delay_function = "constant"
    }

ほぼ繰り返しになってしまいますが、以下のような設定を意味しています。

  • restart 設定により 168 時間の間(interval)に最大 15 回(attempts) リトライする
    • 各リトライ前に 15 秒の遅れ(delay)をもたせる
    • mode fail のためリトライを失敗し続けた場合 status は failed となる
  • status が failed の場合 reschedule 設定により5 秒の遅れ(delay)の後 job の実行を上記の restart 設定で再計画する
    • 24 時間の間(interval)に 1 回(attempts)のみ再計画し、それも失敗した場合は status を failed として再計画は行わない

type system

system job は Nomad クラスタの全ノードで実行したい job に使用します。 service job に constraint を設定すれば同じようなことができるので正直使ったことはないですが、クラスタにノードを増やした時に即座に system job の task が動いてくれるようなので、ユースケースによっては有用そうです。

restartservice job と同じデフォルト値で、 reschedule はそもそも設定できないようです。説明は省略します。

検証

Vagrant 上に動かした 1 ノードの Nomad で検証しました。 reschedule は別ノードでリトライする機能なのですが、 1 ノードしかない場合同じノードでリトライしてくれます。そのへんは手抜きしましたw

実行しているのは pythonワンライナーで現在時刻を出力してエラー終了するものです。

https://github.com/innossh/nomad-example/blob/v0.0.3/jobs/default-service.nomad#L24-L31

      config {
        image = "python:3.7.0-alpine3.7"
        command = "python3"
        args = [
          "-c",
          "from datetime import datetime; now = datetime.utcnow(); print(now); raise Exception('Failed at ' + str(now))"
        ]
      }

まずシンプルな方の batch job です。 run した後の status の確認は running もしくは pending になっているかと思います。

vagrant@nomad:~$ nomad status default-batch
ID            = default-batch
Name          = default-batch
Submit Date   = 2018-10-07T04:05:09Z
Type          = batch
Priority      = 50
Datacenters   = dc1
Status        = running
Periodic      = false
Parameterized = false

Summary
Task Group     Queued  Starting  Running  Failed  Complete  Lost
default-batch  0       1         0        0       0         0

Allocations
ID        Node ID   Task Group     Version  Desired  Status   Created  Modified
211bee95  5d14b0a9  default-batch  0        run      pending  9s ago   5s ago
vagrant@nomad:~$ nomad logs `nomad status default-batch | grep -A 2 Allocations | tail -1 | cut -f1 -d' '`
2018-10-07 04:05:09.933803

少し待って標準出力を見てみると

vagrant@nomad:~$ nomad status default-batch
ID            = default-batch
Name          = default-batch
Submit Date   = 2018-10-07T04:05:09Z
Type          = batch
Priority      = 50
Datacenters   = dc1
Status        = running
Periodic      = false
Parameterized = false

Summary
Task Group     Queued  Starting  Running  Failed  Complete  Lost
default-batch  0       1         0        0       0         0

Allocations
ID        Node ID   Task Group     Version  Desired  Status   Created    Modified
211bee95  5d14b0a9  default-batch  0        run      pending  2m21s ago  7s ago
vagrant@nomad:~$ nomad logs `nomad status default-batch | grep -A 2 Allocations | tail -1 | cut -f1 -d' '`
2018-10-07 04:05:09.933803
2018-10-07 04:05:30.105739
2018-10-07 04:05:53.141476
2018-10-07 04:06:13.930153
2018-10-07 04:06:34.431342
2018-10-07 04:06:57.430020
2018-10-07 04:07:20.109387

Allocation は変わらないままリトライが実行され標準出力に現在時刻が増えていっています。 batch job は 15 回のリトライがあるので待ってみます。

vagrant@nomad:~$ nomad logs `nomad status default-batch | grep -A 2 Allocations | tail -1 | cut -f1 -d' '`
2018-10-07 04:05:09.933803
2018-10-07 04:05:30.105739
2018-10-07 04:05:53.141476
2018-10-07 04:06:13.930153
2018-10-07 04:06:34.431342
2018-10-07 04:06:57.430020
2018-10-07 04:07:20.109387
2018-10-07 04:07:42.135518
2018-10-07 04:08:02.834546
2018-10-07 04:08:24.017199
2018-10-07 04:08:47.157840
2018-10-07 04:09:07.636692
2018-10-07 04:09:30.495028
2018-10-07 04:09:51.994603
2018-10-07 04:10:13.054629

15 回の出力が確認できました。このあと status をみると

vagrant@nomad:~$ nomad status default-batch
ID            = default-batch
Name          = default-batch
Submit Date   = 2018-10-07T04:05:09Z
Type          = batch
Priority      = 50
Datacenters   = dc1
Status        = pending
Periodic      = false
Parameterized = false

Summary
Task Group     Queued  Starting  Running  Failed  Complete  Lost
default-batch  0       0         0        1       0         0

Future Rescheduling Attempts
Task Group     Eval ID   Eval Time
default-batch  f6a1d563  4s from now

Allocations
ID        Node ID   Task Group     Version  Desired  Status  Created    Modified
211bee95  5d14b0a9  default-batch  0        run      failed  5m30s ago  0s ago

Future Rescheduling Attempts の文字を確認することができます。 4s from now となっていますね。 さらに status を確認すると

vagrant@nomad:~$ nomad status default-batch
ID            = default-batch
Name          = default-batch
Submit Date   = 2018-10-07T04:05:09Z
Type          = batch
Priority      = 50
Datacenters   = dc1
Status        = running
Periodic      = false
Parameterized = false

Summary
Task Group     Queued  Starting  Running  Failed  Complete  Lost
default-batch  0       1         0        1       0         0

Allocations
ID        Node ID   Task Group     Version  Desired  Status   Created    Modified
088b5cb4  5d14b0a9  default-batch  0        run      pending  8s ago     3s ago
211bee95  5d14b0a9  default-batch  0        run      failed   5m42s ago  12s ago

reschedule により新たな Allocation が増えています。本来はここで別のノードに Allocation が増えますが、1 ノードなので同じノードになっています。

さらにさらに新しい Allocation で 15 回の標準出力を待った後で status を確認すると

vagrant@nomad:~$ nomad status default-batch
ID            = default-batch
Name          = default-batch
Submit Date   = 2018-10-07T04:05:09Z
Type          = batch
Priority      = 50
Datacenters   = dc1
Status        = dead
Periodic      = false
Parameterized = false

Summary
Task Group     Queued  Starting  Running  Failed  Complete  Lost
default-batch  0       0         0        2       0         0

Allocations
ID        Node ID   Task Group     Version  Desired  Status  Created     Modified
088b5cb4  5d14b0a9  default-batch  0        run      failed  5m50s ago   26s ago
211bee95  5d14b0a9  default-batch  0        run      failed  11m24s ago  5m54s ago

job が完全に failed で終了(dead)していることが見てとれます。

ハマりがちなのが、 nomad status (job 名指定なし) コマンドで全 job の status を確認して全て running なので問題なしかと安心していると、 restart,reschedule の設定によって何度もリトライし続けているだけで、実際 task の内容はコケまくってるのに気づかない、みたいな状況が起こりうるので気をつけてください。 nomad status コマンドでは最後の dead になった時点でようやく job としての status が dead になり気づくことができます。

vagrant@nomad:~$ nomad status
ID             Type   Priority  Status  Submit Date
default-batch  batch  50        dead    2018-10-07T04:05:09Z

...

続いて service job ですが長くなりすぎたので gif で確認しましょう。 python で実行してる内容は同じなのでそもそも常駐 job ではないのですが fail の検証なのでまあよいでしょう。

https://github.com/innossh/nomad-example/raw/v0.0.3/nomad-example-service-reschedule.gif

上部が vagrant status default-service の結果、下部が最新の allocation の stdout になるように watch コマンドを実行してます。 設定どおり、 リトライ-> failed して reschedule -> 新しい allocation -> リトライ -> ... という挙動になりました。

これも余談ですが、 service job の restart,reschedule の挙動が不安定で、初回起動時になぜか batch job のデフォルト値が設定されているかのように振る舞う時がありました。再現できたら issue 登録しようと思いましたが問題なく振る舞う時もあるのでなんだかなあという感じです。

Nomad の Web UI で確認するとリアルタイムで status 表示などが変わるのでそちらも助けになると思います。

f:id:innossh:20181007152944p:plain

...

おまけで periodic job の挙動も確かめましたが、こちらは restart,reschedule の設定を理解していれば特に難しいことはありませんでした。

periodic Stanza - Job Specification - Nomad by HashiCorp

  periodic {
    cron             = "*/15 * * * * *"
    prohibit_overlap = true
  }

prohibit_overlaptrue であれば、 failed な job が reschedule されて残っていると次の period の job は実行されません。

逆に prohibit_overlapfalse であれば、 failed しようが関係なく、単純に period 毎に restart,reschedule 設定が適用された job が実行されます。毎 period で failed し続けた場合、何重にも job が起動するということですね。

バッチの作りにもよりますが、おそらく何重にも起動されると主にメモリなどのリソースを意図せず使い果たすことにもなるので、基本的には prohibit_overlaptrue にする方が安全だと思います。

まとめ

もちろん何を動かすかによって最適な値があると思うのでそれぞれの job で restart,reschedule の設定を正しくやることが望ましいです。 が、一般論として service job の設定は

    restart {
      interval = "1m"
      attempts = 2
      delay    = "15s"
      mode     = "fail"
    }
    reschedule {
      delay          = "30s"
      delay_function = "exponential"
      max_delay      = "1h"
      unlimited      = true
    }

デフォルトのままでも良さそうです。

一例ですが、 hourly な batch job の設定は

  periodic {
    cron             = "@hourly"
    prohibit_overlap = true
  }
...
    restart {
      attempts = 2
      delay    = "30s"
      interval = "1h"
      mode     = "fail"
    }
    reschedule {
      attempts  = 0
      unlimited = false
    }

2 回やり直してだめなら failed 終了とし、何かしらの監視手段を用意して対応する、みたいな形が良いかなと思います。

もしかしたら batch に限らず reschedule はオフにして restart の方のリトライが失敗したら監視でアラートあげて、それ以上はリトライしないという方がシンプルで扱いやすいかもしれませんね。