行動すれば次の現実

テック中心の個人ブログ

Herokuのworker dynoが突然遅くなったときに確認すべきこと

Herokuのworker dynoのパフォーマンスが数日前から突然悪くなった。

今まで30秒程度掛かっていたバックグラウンド処理が10分程度掛かるようになった。

直近で心当たりのあるリリースはなかったため、調査することにした。

丸一日調査して解決はしたのだが、思っていたよりも根が深く、自身の学びにもなったのでまとめておく。

前提情報

  • Rails5.2
  • Jobフレームワーク: Sidekiq

  • Heroku

    • web dyno * 2
    • worker dyno * 2 (内1つはcron用)
  • DB

    • posgresql
  • 監視ツール

    • Papertrail
    • NewRelic

Papertrailでworker dynoのログを確認する

まずはログを確認する。Pepartrailを入れているので、問題が発生したJobIDをもとにログを特定する。 (各処理の実行時間などから問題の原因をある程度推測できるケースが多い)

ActiveRecordが発行しているログからDBへのアクセス時間が極端に遅くなっていることがわかった。 通常時はテーブルのUpdateに1ms程度掛かっていた処理が、100ms程度掛かっていることがわかった。

「DBアクセス周りになにか原因があるのではないか?」と推測する。

NewRelicでパフォーマンスを確認する

念の為NewRelic APMも確認する。 CPUやMemoryの状況に異常は見られなかった。 Transaction traceを確認するとDB Queryのパフォーマンスに異常はなく、アプリケーションコードの実行速度が極端に遅いことがわかった。

ActiveRecordの処理時間は生のDB Query以外の処理時間も含まれている。

「DBが原因ではない」と推測する。

DBが原因ではないことの確認

念の為web dynoからのアクセス時間を図ってみたところ、異常は見られなかった。

  • webからのアクセスは遅くない
  • workerからのアクセスのみ遅い

上記よりDBが原因ではないことがわかった。

「workerで動くアプリケーションに原因があるのではないか?」と推測する。

デバッグログを仕込む

workerで実行しているJobアプリケーションに対してデバックログを仕込んだ。

デバッグを仕込む際は、

  1. 大きめなメソッド単位でログを仕込んで、どこでメソッド時間がかかっているか特定する
  2. 時間が掛かっているメソッドが特定できたら、ドリルダウンで情報が把握できるようにあらに詳細なログを仕込む

というステップを踏む。

1の段階で全体的に遅いということがわかった。

「特定のコードが遅いというわけではなくプロセス自体が遅いのではないか?」と推測する。

Herokuのmetricsを確認

原因がわからず小一時間息詰まっていたが、初心に戻ってHerokuのMetricsタブを確認することにした。

するとDyno Loadが常に1以上稼働していることがわかった。

dyno load
dyno load

試しにworker dynoをもう一つ起動してjobを実行してみると もう一つのworkerに割り振られたJobは通常通りのパフォーマンスで処理を終えたことが確認できた。

「デーモンプロセスが動いていて、dynoを専有しているのではないか?」と推測する。

Sidekiqの管理画面を確認

Sidekiqの管理画面を確認すると実行中のジョブプロセスが常に1あることが判明。 worker dynoで再起動してみる。するとSidekiqの性質上、自動でリランが走った。 リランされたジョブがなぜか終了されることなく、デーモン化していることがわかった。

「アプリケーションコードで無限ループしているのではないか?」と推測する。

コードを確認

対象クラス内で無限ループが発生しそうなコードがないか調査したところ、whileを使用している処理が一箇所見つかる。 ある特定の条件の場合、whileを抜けられずに無限ループしてしまうことが判明。

原因は、

「アプリケーション内の無限ループによりworker dynoを専有していたこと」

パッケージシステムにカスタマイズ対応を入れる場合、どのようにソースコードを管理すべきか

弊社ではクラウド型のWebアプリケーションパッケージシステムを開発しています。 基本的にはパッケージに搭載した機能のみを顧客に使用してもらいたいのですが、当然のようにカスタマイズ要望が生まれます。

カスタマイズ要望は、企業に特化した要件が多く、抽象的というよりは具体的な内容です。

具体的な要望でも、要件を整理して抽象度の高い汎用性のある機能に落とし込めればよいのですが、あまりにも特化した要望の場合はそれが出来ないことがあります。

とはいえ、これらを全て切り捨ててしまうと業務が回らないという自体になりますので、パッケージに影響の少ない方法で機能を提供できないかという課題が生まれます。

そのような場合にどのような開発手法的アプローチがあるのか考えてみたいと思います。

顧客ごとにブランチを分ける

パッケージとしての本ブランチ(master)と顧客ごとにブランチを作成する方法です。

  • メリット:他顧客に影響ないのでカスタマイズを好き放題できる
  • デメリット: ブランチの管理が大変。masterへのマージ、各ブランチへのマージなどの業務が発生して煩雑になる

マイクロサービス化する

カスタマイズ機能をマイクロサービス化する方法です。パッケージとはコードベースが別になります。アプリサーバーなども別に用意します。

  • メリット:パッケージのコードベースの煩雑化を防げる。影響範囲が絞られるのでメンテナンス性が高い
  • デメリット:マイクロサービスとして切り出す上で、アーキテクチャの見直しをしなければならない。複数コードベースを横断して開発する必要がある。

フラグで分岐させる

機能を使用するかどうかのフラグで処理を強引に分岐させる方法です。

  • メリット:一番手っ取り早い、コードベースが小規模段階ではスピードをもって開発することが可能
  • デメリット:コードベースが肥大化し、分岐処理によって複雑化する。しっかりテストを書かないと品質担保が難しい

我々の結論

我々の結論としては「フラグで分岐させる」を採用することにしました。

弊社のパッケージシステムの場合、まだ完全にはPMF(プロダクトマーケットフィット)していないプロダクトなので、スピードを重視したいためです。

メンテナンス性やデグレードの懸念については自動テストである程度担保できると判断しました。 理想は「マイクロサービス化する」ですが、現状ではそれを構築するほどのリソース確保ができていないので今回は見送りしました。

RubyとJavascriptにおける連想配列の順序保証の違い

RubyとJavascriptでは連想配列(Rubyの場合はHash、Javascriptの場合はオブジェクトリテラル)の順序保証が異なります。

最近はバックエンドでRuby、フロントエンドはJavascriptの構成にして開発するケースが増えています。

RubyでAPIの結果を連想配列で返し、Javascript側で連想配列をeachして順番に処理を行う場合は、そのギャップに注意が必要です。

Rubyの場合はHashの順序が保証される

Ruby(v1.9以降)の場合、Hashの順序が保証されます。

hash = { '1':'one', '2':'two', '4':'four', '3':'three' }
p hash
=>  {:"1"=>"one", :"2"=>"two", :"4"=>"four", :"3"=>"three"}

hash.each do |k, v|
  p v
end

=> "one"
=> "two"
=> "four"
=> "three"

Javascriptの場合はオブジェクトリテラルの順序が保証されない

Javascriptの場合、オブジェクトリテラルの順序が保証されません。

const hash = { 1:'one', 2:'two', 4:'four', 3:'three' }
console.log(hash)
=> {1: 'one', 2: 'two', 3: 'three', 4: 'four'}

Object.values(hash).forEach((value) => {
  console.log(value)
});
=> "one"
=> "two"
=> "three"
=> "four"

そのため、Javascriptで順序を保ちたい場合は、順序を管理するための配列を別途用意する必要があります。

const hash = {
  entities:  { 1:'one', 2:'two', 4:'four', 3:'three’ },
  orders: [1 ,2 ,4 ,3]
}

hash.orders.forEach((k) => {
  const value = hash.entities[k];
  console.log(value)
});
=> "one"
=> "two"
=> "four"
=> "three"

静的クラスっぽくRubyのモジュールを使いたい

Rubyのモジュール(module)といえばミックスインというイメージが強い。

ミックスインは便利だが、わざわざミックスインで組み込まずに、ユーティリティクラスのようにそのままメソッドを呼び出したいケースがある。 (Javaでいう静的クラスを定義して静的メソッドを呼び出すイメージ)

モジュールでもそのようなことが実現できる

module HashModule
  extend ActiveSupport::Concern

  def self.to_hash(list)
    hash = { entities: {}, orders: [] }
    orders = []
    list.each do |data|
      orders << data.id
      hash[:entities][data.id] = data
    end
    hash[:orders] = orders
    hash.to_h
  end
end

products = Product.all
HashModule.to_hash(products)

まとめて定義したいときは class << self を使うほうがタイプ数が減っておすすめ。

module HashModule
  extend ActiveSupport::Concern

  class << self
    def to_hash(list)
      hash = { entities: {}, orders: [] }
      orders = []
      list.each do |data|
        orders << data.id
        hash[:entities][data.id] = data
      end
      hash[:orders] = orders
      hash.to_h
    end
  end
end

products = Product.all
HashModule.to_hash(products)

Github Projectsを利用したタスク管理と運用ルール

アプリ開発する上で、様々なプロジェクトのタスク管理ツールを使ってきましたが、最終的にGithub projectsに落ち着きました。

弊社プロジェクトで実際に運用しているルールは以下の通りです。 小規模なプロジェクトであれば、問題なく回るのではないかと考えています。

  • リポジトリごとにProjectを一つ作成する
  • Columnは以下の通りとする
    • Inbox: いつかやるけど今じゃない
    • ToDo: やる必要があるもの
    • in Progress: 今やってるもの
    • Check: 作業が終わってるけど本番確認がまだ
    • Done: リリースしたもの(closeしたら自動的にDoneに移動する)
    • Pending: 何らかの理由で作業が止まっているもの
  • 開発手法はGithub Flowを用いる
  • ブランチ名は「issue番号-概要」
    • 1234-fix-conditions
  • PRのdescriptionに issueのリンクを貼る
    • issueとPRが関連付けされる
  • issue:PRは1:N
    • 一つのissueにつき、複数のPRを作成しても良い
    • 全てのPRがマージされたらissueをCheckに移動させる
  • 大規模な機能開発の場合は中間ブランチを作成する
    • Epicのような運用
    • 例) master -> calc_orders/master -> cals_orders/1234-fix-conditions