Slide 1

Slide 1 text

HerokuでSidekiqを監視する 方法を確立した
 2020-02-28 @masutaka


Slide 2

Slide 2 text

自己紹介
 ● 増田貴士(@masutaka)
 ● 株式会社フィードフォース
 ● EC Boosterの雑用係
 ● 最近のマイブームは玄米とビタミンB群とボディクリーム
 ● 最近の悩みはドラクエウォークと足底筋膜炎との両立
 https://www.feedforce.jp/ 


Slide 3

Slide 3 text

ビタミンB群
 ● ビタミンB1: 糖質をエネルギーにする
 ● ビタミンB2: 脂肪をエネルギーにする
 ● ビタミンB6: アミノ酸の代謝に必要
 ● ビタミンB12: ヘモグロビンの合成に必要
 ● 他、ナイアシン、パントテン酸、葉酸、ビオチン


Slide 4

Slide 4 text

EC Booster
 国内初のGoogleショッピング広告自動運用ツール
 https://ecbooster.jp/ 


Slide 5

Slide 5 text

商品別レポート機能のリリース https://www.feedforce.jp/release/19886/


Slide 6

Slide 6 text

商品別レポート機能 広告出稿している商品一覧と詳細情報がわかる機 能。 Google Ads APIをバックグラウンドジョブで呼ぶだけ ではあるが、それだと情報が足りないので、S3 Selectも使って、ジョブ中でJoinしたりしている。 何が言いたいのかというと、時間がかかり得るバック グラウンド処理を含む機能。

Slide 7

Slide 7 text

EC Boosterの技術スタック
 Heroku App Web Dyno GraphQL Client (apollo-client) GraphQL Server (graphql-ruby on Rails) Worker Dyno Chrome (headless mode) chromedriver sidekiq Heroku Postgres Heroku Redis

Slide 8

Slide 8 text

Sidekiq ● Ruby実装のバックグラウンドジョブライブラリ ● Webアプリで時間がかかる処理を非同期実行させたり、 定期実行バッチ処理などに使われる https://sidekiq.org/ 


Slide 9

Slide 9 text

ジョブの遅延とUXの低下 ● ジョブが遅延すると、テーブル表示やCSVダウンロード が遅延する ● ジョブの遅延がそのままUXの低下に繋がり得る

Slide 10

Slide 10 text

監視の必要性 ● Sidekiqを監視をしないとジョブの遅延に気づけない ● そこまでトラフィックはないのでログを毎日見るという 方法もあるけど...

Slide 11

Slide 11 text

HerokuでのSidekiq監視の知見が見つか らない。みんなどうしているんだろう?

Slide 12

Slide 12 text

Slack HerokuJP-UGで聞いてみた https://herokujp-ug.slack.com/archives/C9LRC3M25/p1578381627030100

Slide 13

Slide 13 text

メトリクス収集 ● LibratoのCustom log-based metricsを使えば良さそう ● sample#database.size=40.9MB のようなログを出力す るだけで、Libratoが勝手にメトリクスとして記録してく れるスゴい機能 https://devcenter.heroku.com/articles/librato#custom-log-based-metrics

Slide 14

Slide 14 text

トリガーはどうしようか? ● ApplicationControllerとかにログを仕込む ○ アクセスがなければメトリクスを収集できないし、多ければ収集しすぎる ● Heroku Scheduler ($0/mo) ○ 最短インターバルが10分なのでダメ ● Cron To Go Add-on ($8/mo) ○ 最短インターバルは1分なのでギリギリ使える。しかし、そのたびにOne-Off Dynoが起動す るのは大げさすぎる ● 専用のworker Dynoを起動して、loopでスクリプトを実 行 ($7~25/mo) ○ 大げさだし、コスト感もダメ ● 同じworker Dynoのsidekiq-cronで収集 ○ 監視対象のキューが詰まっていたら自身が呼ばれない

Slide 15

Slide 15 text

これは難しい...

Slide 16

Slide 16 text

待てよ?以前調べた Ruby Language Metrics収集の 仕組みは使えないだろうか?

Slide 17

Slide 17 text

今日のために書きました https://developer.feedforce.jp/entry/2020/02/13/150000


Slide 18

Slide 18 text

できたーーーー https://github.com/feedforce/heroku-buildpack-sidekiq-metrics

Slide 19

Slide 19 text

メトリクス収集の仕組み
 Web.1 Dyno(Web.2以降のDynoでは収集しない) /app/bin/sidekiq-metrics (ruby script) /app/.profile.d/ruby-sidekiq-metrics.sh Sidekiq (1) 30秒に1回実行 (2) メトリク ス 取 得 Worker Dyno (3) 標準出力 Librato (Heroku Add-on) HerokuではLogplexというログ集約エンジンを介し て、各Add-on等にログが送られる

Slide 20

Slide 20 text

送っているログ Feb 28 12:26:20 ecbooster app/web.1 sample#sidekiq.default.size=0 sample#sidekiq.get_master_data.size=0 sample#sidekiq.mailers.size=0 sample#sidekiq.product_report.size=0 sample#sidekiq.slacks.size=0 sample#sidekiq.update_datafeed.size=43 sample#sidekiq.update_master_data.size=0 Feb 28 12:26:20 ecbooster app/web.1 sample#sidekiq.default.latency=0 sample#sidekiq.get_master_data.latency=0 sample#sidekiq.mailers.latency=0 sample#sidekiq.product_report.latency=0 sample#sidekiq.slacks.latency=0 sample#sidekiq.update_datafeed.latency=1577.5242395401 sample#sidekiq.update_master_data.latency=0

Slide 21

Slide 21 text

収集されるメトリクス ● sidekiq.<キュー名>.size ○ 各キューにおける待機状態のジョブ数 ● sidekiq.<キュー名>.latency ○ 各キューにおけるジョブの待機時間

Slide 22

Slide 22 text

設定したアラート1 ● product_reportキューのレイテンシーが30を超えたら Slackに通知(もっと厳しくして良いかも)

Slide 23

Slide 23 text

設定したアラート2 ● sidekiq.product_report.latencyのメトリクスが送信さ れなくなったらSlackに通知(メトリクス収集のバグを想 定)

Slide 24

Slide 24 text

かかった費用 ● トリガー: heroku-buildpack-sidekiq-metrics ○ $0/mo ○ https://github.com/feedforce/heroku-buildpack-sidekiq-metrics ● メトリクス収集: Heroku Add-on Librato ○ $21/mo (Nitro plan) ○ https://elements.heroku.com/addons/librato

Slide 25

Slide 25 text

別解 ● Sidekiq ProのMetrics ○ https://github.com/mperham/sidekiq/wiki/Pro-Metrics ○ $950/year ● heroku-buildpack-datadog ○ https://github.com/DataDog/heroku-buildpack-datadog ○ $15/mo x Dyno number ● 高い

Slide 26

Slide 26 text

今後の予定? ● 各ジョブの実行数や成功数、失敗数等も収集するかも ● とは言え、Bugsnagでエラーは把握しているし、sidekiq webでも見られるので優先順位は低い

Slide 27

Slide 27 text

感想 ● 現在のEC Boosterに見合った監視を実装できたと思う ● アプリケーションには何も実装していないため、取り外 しは簡単 ● オーバースペックな技術は採用したくなかったので、そ の点は満足した

Slide 28

Slide 28 text

落ち穂拾い


Slide 29

Slide 29 text

よく分からなかったこと ● ruby scriptの中でループしたかったが、標準出力がバッ ファリングされてしまい、定期的なログ出力ができな かった ● https://github.com/feedforce/heroku-buildpack-s idekiq-metrics/pull/1 ● $stdout.sync = true はしていたのに。$stdout.flush まで必要だったのかな(未確認)

Slide 30

Slide 30 text

Heroku Redisのログ形式 2020-02-04T07:53:26.000Z ecbooster-sidekiq-metri-ck0pam app/heroku-redis source=REDIS addon=redis-defined-77910 sample#active-connections=10 sample#load-avg-1m=0.18 sample#load-avg-5m=0.125 sample#load-avg-15m=0.1 sample#read-iops=0 sample#write-iops=0 sample#memory-total=15664264kB sample#memory-free=12350252kB sample#memory-cached=1622852kB sample#memory-redis=507704bytes sample#hit-rate=0.11266 sample#evicted-keys=0 →今回使用したLibratoのCustom log-based metrics形式で出力していたこと を発見した。Heroku Postgresも。

Slide 31

Slide 31 text

Librato上でRedisの可視化やアラート設定が出来た ※ Heroku PostgresはLibratoに始めからグラフがあるのに、 Heroku Redisは作らないとない

Slide 32

Slide 32 text

終わり