こしごぇ(B)

旧:http://d.hatena.ne.jp/koshigoeb/

delayed_job の logrotate を使ったログローテーションって

どうやるものなんだろう。

  • logrotate を使わず TwP/logging の daily ローテーションもありだけど
  • logrotate の copytruncate は最終手段
  • delayed_job を Capistrano でオプション付きで起動してるので、logrotate の postscript で restart や start する場合は、同じオプションの指定が必要(だと思う)

Unicorn::Util.reopen_logs を使って USR1 シグナルでログのリオープンできるようにしたら良いのかなと思ったけど、どうも上手くいかない模様。

どうやら、delayed_job の Delayed::Worker.after_fork にて "a+" モードでリオープンしているため、Unicorn::Util.is_log? で許容するモードにマッチせずに対象外とされる模様。 (一律で a+ モードで開き直すという挙動は、それはそれで大丈夫なのかな?)

    def self.before_fork
      unless @files_to_reopen
        @files_to_reopen = []
        ObjectSpace.each_object(File) do |file|
          @files_to_reopen << file unless file.closed?
        end
      end

      backend.before_fork
    end

    def self.after_fork
      # Re-open file handles
      @files_to_reopen.each do |file|
        begin
          file.reopen file.path, 'a+'
          file.sync = true
        rescue ::Exception # rubocop:disable HandleExceptions, RescueException
        end
      end
      backend.after_fork
    end

んー、どうするのがいいんだろうか。

こんな感じはありだろうか?

class Delayed::Worker
  module TrapUsr1ForReopenLogs
    def start
      ObjectSpace.each_object(File) do |file|
        begin
          next unless file.path.ends_with?('.log')
          file.reopen file.path, 'a'
          file.sync = true
        rescue ::Exception # rubocop:disable HandleExceptions, RescueException
        end
      end

      trap('USR1') do
        Thread.new { say 'Reopen logs...' }
        Unicorn::Util.reopen_logs
      end
      super
    end
  end
  prepend Delayed::Worker::TrapUsr1ForReopenLogs
end

Fluent 経由で Bugsnag に送信する試み

ひとまず、ざっくりと形にはなったけど、これが上手く運用に乗る程度のものかは分からない。

  1. koshigoe/logging-bugsnagTwP/logging を拡張し、error 以上のログを bugsnag/bugsnag-ruby の deliver に渡す
  2. koshigoe/bugsnag-delivery-fluentbugsnag/bugsnag-ruby の deliver を拡張し、Fluentd に URL とリクエストボディを渡す
  3. koshigoe/fluent-plugin-bugsnag で Fluentd から Bugsnag に送信する

追記:書いた

ActiveSupport::Logger#broadcast は異なるレベルのロガーを束ねるには適さない?

セッターの挙動を見るに、レベルやフォーマッタなどは全て同一のものを使う前提にあるっぽい。 extend 後にセッターを呼ばなければ各ロガーで設定したものを使う事はできるが、 quiet_assetsActiveSupport::Logger#silence などを使った場合はレベルが変更されてしまうので、できないものだと考えて使わないと危険な感じがする。

という事で、 quiet_assets を使っていても追加ロガーのログレベルを変更されない様に、懐かしの TwP/logging を使って Bugsnag.notify を呼ぶ様にしてみたのが、以下のプラグイン

colbygk/log4r じゃないのは、なんとなくでしかない。土地感覚が無いのと、GitHub スター数と、更新日で決めただけ。Ruby Toolbox だと log4r の方が人気だったんだけど。

Rails での利用を想定して書いたので、TwP/logging-rails と組み合わせて以下の様な感じで使う。

TwP/logging-email みたいにッファリングとかの遅延措置はしてないので、応答時間がシビアな場面では使えなそうな点は気になりつつ放置…。

Rails.logger.error(msg) したら Bugsnag にも通知しちゃうやつ

注意: quiet_assets など、broadcast 後に Rails.logger.level= する様な実装をしているケースには未対応。

こんな感じでやってみた。

  • lib/ext と lib/bugsnag に分けたのは、Bugsnag クライアントが lib/bugsnag にマッチしたバックトレース行を読み飛ばしてくれる実装になっているから
  • Bugsnag.configure の config.logger をセットしてるのは、デフォルトの Rails.logger を Bugsnag クライアント内部で使っているため(再帰回避)
  • broadcast するタイミングはどこが適切かよくわかってない
diff --git a/config/application.rb b/config/application.rb
index 3ddf16f..e10572f 100644
--- a/config/application.rb
+++ b/config/application.rb
@@ -17,6 +17,8 @@ Bundler.require(*Rails.groups)
 
 module RailsExampleActivesupportLoggerBroadcast
   class Application < Rails::Application
+    config.autoload_paths += %W(#{config.root}/lib/ext #{config.root}/lib/bugsnag)
+
     # Settings in config/environments/* take precedence over those specified here.
     # Application configuration should go into files in config/initializers
     # -- all .rb files in that directory are automatically loaded.
@@ -31,5 +33,11 @@ module RailsExampleActivesupportLoggerBroadcast
 
     # Do not swallow errors in after_commit/after_rollback callbacks.
     config.active_record.raise_in_transactional_callbacks = true
+
+    config.after_initialize do
+      error_logger = ErrorMonitor::Logger.new(:bugsnag)
+      error_logger.level = Logger::WARN
+      Rails.logger.extend ActiveSupport::Logger.broadcast(error_logger)
+    end
   end
 end
diff --git a/config/initializers/bugsnag.rb b/config/initializers/bugsnag.rb
index 3b6d7ae..2bff2a2 100644
--- a/config/initializers/bugsnag.rb
+++ b/config/initializers/bugsnag.rb
@@ -1,3 +1,4 @@
 Bugsnag.configure do |config|
   config.api_key = ENV['BUGSNAG_API_KEY']
+  config.logger = ActiveSupport::Logger.new(Rails.root.join('log/bugsnag.log'))
 end
diff --git a/lib/bugsnag/error_monitor/bugsnag.rb b/lib/bugsnag/error_monitor/bugsnag.rb
new file mode 100644
index 0000000..620e0ea
--- /dev/null
+++ b/lib/bugsnag/error_monitor/bugsnag.rb
@@ -0,0 +1,15 @@
+module ErrorMonitor
+  class Bugsnag
+    def write(message)
+      if message[:options][:severity] >= Logger::ERROR
+        message[:options][:severity] = 'error'
+      elsif message[:options][:severity] >= Logger::WARN
+        message[:options][:severity] = 'warning'
+      else
+        message[:options][:severity] = 'info'
+      end
+
+      ::Bugsnag.notify(message[:exception], message[:options])
+    end
+  end
+end
diff --git a/lib/ext/error_monitor/logger.rb b/lib/ext/error_monitor/logger.rb
new file mode 100644
index 0000000..cd4db68
--- /dev/null
+++ b/lib/ext/error_monitor/logger.rb
@@ -0,0 +1,20 @@
+require 'active_support/logger'
+
+module ErrorMonitor
+  class Logger < ActiveSupport::Logger
+    def initialize(*args)
+      @progname = nil
+      @level = ERROR
+      @default_formatter = proc do |severity, datetime, progname, msg|
+        {
+          exception: RuntimeError.new(msg),
+          options: {
+            severity: SEV_LABEL.index(severity)
+          }
+        }
+      end
+      @formatter = nil
+      @logdev = "ErrorMonitor::#{args.first.to_s.camelize}".constantize.new
+    end
+  end
+end

追記

取り急ぎ Gem にしてみた。

ActiveSupport::Logger.broadcast と quiet_assets gem

quiet_assets を使っていると ActiveSupport::Logger.broadcast で追加したロガーのレベルが Rails.logger.level にされてしまう模様。

ざっくり言うと、以下の様な事が起きる。

error_logger = ActiveSupport::Logger.new(Rails.root.join('log/error.log'))
error_logger.level = Logger::ERROR
Rails.logger.extend ActiveSupport::Logger.broadcast(error_logger)
# 複数ロガーは↑までで完了
# 本当は↓はやらないんだけど、quiet_assets 使っちゃうとこうなる
Rails.logger.level = Rails.logger.level

quiet_assets 捨てれば解決だけど、どうしたものかな。

FactoryGirl を使って冪等な Database seeding をやってみた

development, test 以外で FactoryGirl を使うのどうなんだ、という話は全力で脇に置く。こういう誤魔化し方もあるのかな、という試み。

んー、seeds.rb で find_or_create_by を書かなくて良い、程度のおもちゃかな…。

構造

db/ 以下に色々置く感じの構造。

$ tree db/seeds
db/seeds
├── development.rb
├── factories
│   ├── cities.rb
│   ├── countries.rb
│   └── prefectures.rb
├── factories.rb
├── production.rb
└── test.rb
  • rake db:seed すると db/seeds/#{env}.rb が require されてコードが実行される
    • 共通処理書きたければ、各ファイルから共通ファイル require する、とか?
  • db/seeds/factories.rb には共通処理を書いておく
  • db/seeds/factories/**/*.rb にファクトリを置く
    • ファクトリは initialize_with { find_or_initialize_by } して冪等保証してるだけ

db/seeds.rb

これで spec/factories/ の方との干渉を防げるか自信なし。

表出力は本題とは関係なくて適当に。 Thread.current も特に意味はなく適当に。

require 'factory_girl'

include FactoryGirl::Syntax::Methods

begin
  original_definition_file_path = FactoryGirl.definition_file_paths
  FactoryGirl.definition_file_paths = %W(db/seeds/factories)
  FactoryGirl.reload

  begin
    Thread.current[:seeding_results] = Hash.new {|h, k| h[k] = [] }

    ActiveRecord::Base.transaction do
      require_relative "seeds/#{Rails.env}"
    end

    Thread.current[:seeding_results].each do |klass, ids|
      puts Hirb::Helpers::AutoTable.render(klass.where(id: ids))
    end
  end
ensure
  FactoryGirl.definition_file_paths = original_definition_file_path
end

使い方

ファクトリを書く

冪等保証のために initialize_with { find_or_initialize_by } を使っているので、モデルごとにファクトリを作る必要がある。

ファクトリは db/seeds/factories/ 以下に配置する想定。

FactoryGirl.define do
  factory :prefecture do
    initialize_with { Prefecture.find_or_initialize_by(country: country, name: name) }
  end
end

seed を書く

実際の seed 処理は db/seeds/#{Rails.env}.rb に書く想定なので、それぞれ書く必要がある。

create(:country, name: '日本') do |japan|
  create(:prefecture, country: japan, name: '東京都') do |tokyo|
    create(:city, prefecture: tokyo, name: '千代田区')
    create(:city, prefecture: tokyo, name: '港区')
  end
  create(:prefecture, country: japan, name: '神奈川県') do |kanagawa|
    create(:city, prefecture: kanagawa, name: '横浜市')
    create(:city, prefecture: kanagawa, name: '川崎市')
  end
end

Heroku で Reverse Proxy

ろくに調べもせず、明後日の方向に進んでいる気がするけれど。

require 'rack/reverse_proxy'

if ENV['BASIC_AUTH_USERNAME'] && ENV['BASIC_AUTH_PASSWORD'] && !ENV['BASIC_AUTH_USERNAME'].empty? && !ENV['BASIC_AUTH_PASSWORD'].empty?
  use Rack::Auth::Basic do |username, password|
    username == ENV['BASIC_AUTH_USERNAME'] && password == ENV['BASIC_AUTH_PASSWORD']
  end
end

use Rack::ReverseProxy do
  reverse_proxy_options preserve_host: true, replace_response_host: true
  if ENV['BASIC_AUTH_USERNAME'] && ENV['BASIC_AUTH_PASSWORD'] && !ENV['BASIC_AUTH_USERNAME'].empty? && !ENV['BASIC_AUTH_PASSWORD'].empty?
    reverse_proxy '/', ENV['REVERSE_URL'], username: ENV['BASIC_AUTH_USERNAME'], password: ENV['BASIC_AUTH_PASSWORD']
  else
    reverse_proxy '/', ENV['REVERSE_URL']
  end
end

app = proc do |env|
  [ 200, { 'Content-Type' => 'text/plain' }, 'b' ]
end

run app

jaswope/rack-reverse-proxy を使って実現。gem だとリダイレクト対応がされていないので、GitHub の最新ソースを使用。

igrigorik/em-proxy も試してみたけれど、リダイレクト対応がよく分からず断念した。

最新 master ブランチからアプリを作って、デプロイが成功したら Reverse Proxy アプリの環境変数を更新(heroku config:set)してスイッチする、様な感じで使えれば良いな、と。

  • Heroku の dyno 1 個で Reverse Proxy を動かすのはどうなんだろうか
    • EventMachine 系であれば良いのかな
    • Ruby 実装調べちゃったけど、node.js で Reverse Proxy したら良かったのかな
  • リダイレクト対応が怪しい
    • ログイン後にリダイレクトする様なアプリで試して上手くいったけど…
    • google.com のリダイレクトはループした…

まあ、おもちゃ、かな。