Isono

2013年12月20日

このエントリーをはてなブックマークに追加

Wakame Users Group Advent Calendar 2013 12/20担当 (6回目の登場)

Wakame2-logo-mini

「使ってみました/インストールしてみました」は他の方にお任せし、現場の風景をお届けします。

Wakame-vdcを読み解く

背景

困った時がドキュメントの書き時。今回は下記状況に陥って困った。

環境構成:

  • カナリア環境(しばらく稼働させてる環境)
  • ナイトリービルドによりスモークテスト実施

遭遇した状態:

  • どうやら断続的に node.state が !online状態(onlineではない状態の意味)のhvaが登場
    • 何故、断続的だと判断できるのは、一定時間経過したジョブを処理していたから
  • 何故 !online になっていたのか・・・を調査したいが、今の実装では state 変更をロギングする仕組みがないくて、ログだけでは調査出来ない
  • 今できる事は、state変更ロジックを確認しておく事

未理解な内部実装を理解する為、目出度く?!コードリーディングを開始したのであった。

パッケージバージョン
  • isono 0.2.19
  • wakame-vdc 13.08.0
家族構成

wakame-vdcは、複数agentによってクラスタが構成されていて、各agentはAMQPネットワークに参加している。この辺の詳細は、また後日、追い詰められた時に、書くのだと思う。触れる必要が中たっ為、今回は省略。

dcmgr-agent-cluster

今回の第一調査対象はhva。

役者: hva

hvaを覗いてみる。

wakame-vdc/dcmgr/bin/hva#L35

途中をざっくりと端折りつつ、読み解いて分かった事は、

  • NodeHeartbeatによって各agentがpingしているようだ
  • NodeHeartbeatの結果を集計しているのはNodeCollector
  • NodeCollectorモジュールを刺してるagentが誰か…
役者: collector

NodeCollectorモジュールを刺してるのは、collector。

wakame-vdc/dcmgr/bin/collector#L24

この先は、wakame-vdcではなく、Isono家の謎に迫る必要がある。さよなら、Wakameちゃん。

Isono家の謎 『状態遷移の条件』

状態遷移する条件を探していくと、

isono/node_modules/node_heartbeat.rb#L12-L19

      initialize_hook do
        @timer = EventMachine::PeriodicTimer.new(config_section.heartbeat_offset_time.to_f) {
          rpc = RpcChannel.new(node)
          rpc.request('node-collector', 'notify', manifest.node_id, node.boot_token) do |req|
            req.oneshot = true
          end
        }
      end

heartbeat_offset_time毎に、NodeCollector宛てにnotifyしてる事が分かる。

heartbeat_offset_timeは、何秒?

isono/node_modules/node_heartbeat.rb#L7-L10

      config_section do |c|
        desc "second(s) to wait until send the next heartbeat signal"
        heartbeat_offset_time 10
      end

明示設定が無い場合、 heartbeat_offset_time は 10 秒。

stateが !:online になる条件は?

少なくとも online ではない事までは分かっている。そうなると、!:onelineになる条件と、!:onlineとは、具体的に何かを探っていくと、node_stateモデルに辿り着く。

isono/models/node_state.rb#L23-L45

      def after_initialize
        self[:state] ||= :init
      end

      def process_event(ev, *args)
        case [ev, self.state.to_sym]
        when [:on_ping, :online], [:on_ping, :init], [:on_ping, :timeout]
          self.state = :online
          self.last_ping_at = Time.now
        when [:on_unmonitor, :online]
          self.state = :offline
        when [:on_unmonitor, :timeout]
          self.state = :offline
        when [:on_unmonitor, :init]
          self.state = :offline
        when [:on_timeout, :online], [:on_timeout, :timeout]
          self.state = :timeout
        when [:on_timeout, :init]
          # Do nothing
        else
          raise "Unknown state transition: #{ev}, #{self.state}"
        end
      end

onelineを含め、どんな状態になりえるのかが分かる。

  • init
  • oneline
  • timeout
  • offline

どの条件で、どうなるか・・・わけWakame(やっと使えた!)なので、直感的に分かりやすくしたくて図にしてみると、

isono-fsm

これで状態遷移を俯瞰しやすい。少なくとも普段コードを書かない自分にとっては最高に読みやすい。今回に限らず、今後の調査材料として役立つ。

前述の通りで、!onelineからonlineへ遷移してるのだから、その経路は絞られる。

!onlineからonlineへ遷移してるのだから・・・

online ⇒ timeout ⇒ online だった事が分かって来る。

isono/node_modules/node_collector.rb#L32-L49

            Models::NodeState.dataset.all.each { |row|
              next if row.state == :offline

              diff_time = Time.now - row[:last_ping_at]
              if row.state != :timeout && diff_time > config_section.timeout_sec
                row.process_event(:on_timeout)
                row.save_changes
                event.publish('node_collector/timedout', :args=>[row.values])
              end

              if diff_time > config_section.kill_sec
                row.process_event(:on_unmonitor)

                event.publish('node_collector/killed', :args=>[row.values])
                row.destroy
              end
            }
          }
  • 最終pingから何秒経過しているか
  • とある閾値を越えている場合、timeoutとして判定

と言う事が分かる。

閾値 config_section.timeout_sec は?

isono/node_modules/node_collector.rb#L8-L15

      config_section do
        desc "time in second to recognize if the agent is timed out"
        timeout_sec (10*2).to_f
        desc "the agent to be killed from the datasource after the time of second"
        kill_sec (10*2*2).to_f
        desc ""
        gc_period 20.0
      end
  • 明示指定が無い場合、 timeout_sec は (10*2).to_f => 20.0
Isono家の安否確認まとめ
  • 各agentは、一定時刻(10秒)毎に生存してる事を通知
  • NodeCollectorは、前回の確認時刻から一定時刻(20秒)以内に通知して来たかどうかを確認
    • 時間以内通知の場合は、online
      • 一定時間が経過してる場合は、timeout

Isono家は、20秒以内に返事しないagentを、timeout扱いする。

Isono家の安否確認を踏まえて、当時の状況を考察すると
  • 20秒以内に返事して無いhvaが居た

と言う事までが判明。しかし、何故返事してなかったのかは、謎のまま。Isono家とは違う次元の何かが起きていたようだ。調査は続くのであった。

あとがき

追い詰められた時の学習意欲。

参考文献



編集
@hansode at 10:00|PermalinkComments(0)TrackBack(0)