yyamasakの日記

Railsではデフォルトでcolorize_loggingが有効なので、linuxでは美しいカラー表示になりますよね。

でもWindowsでは邪魔なだけと思って、すぐにcolorize_logging=falseにしていました。

ところが最近、Windowsのコマンドプロンプトでも簡単にANSI escape sequenceを有効にできることが分かりました。

http://bit.ly/79Rwr4

C:\WINDOWS\system32\CONFIG.NT の最後の行に以下の行を一行追加するだけです。

device=%SystemRoot%\system32\ansi.sys

再起動とかしなくても次にコマンドプロンプトを起動するときに読み込まれ、

見事にカラー表示になります。

Rails2.0.2のアプリを2.3.4に対応させてたところ、

チェックボックスの値をparams[:key]で参照すると常にhiddenの値になるという問題が発生していました。

例えば、

<%= check_box_tag 'abc', '1', @key %>
<%= hidden_field_tag 'abc', '0' %>

というテンプレートは

<input id="abc" name="abc" type="checkbox" value="1" />
<input id="abc" name="abc" type="hidden" value="0" />

となって、Submitした結果、チェックが入ってるときは

abc=1&abc=0

入ってないときは

abc=0

となり、Railsは先頭の値を見るので、params[:abc]は"1"か"0"を返すことができていたわけですが....

どうも、この動作が変わったせいで、常に最後の値を返すようになったようです。

今年初めにこれと同じか似たような問題が挙がっていますが、

https://rails.lighthouseapp.com/projects/8994/tickets/1863-check_box-doesnt-work-with-nested-forms

実は最後の値をとる仕様になったというのが正しくて、

ドキュメントの方が対応してないという状況みたいです。

http://github.com/rack/rack/commit/5c00dd698edb953b4bee432fa12a20ba69a067c1

つまり、

checked: abc=0&abc=1

not-checked: abc=0

の後ろの方がparams[:abc]の値になるようになった訳です。

確かに、これに対応すべく、form_helper.rbのcheckboxヘルパの方では、hiddenの方を前にするようになってました。だからこのAPIを使ってる場合は修正の必要はないです。

check_box_tag + hidden_field_tagを使って書いてる箇所はこの順番を逆にしてやる必要がありました。

#actionpack/lib/action_view/helpers/form_helper.rb
def to_check_box_tag(options = {}, checked_value = "1", unchecked_value = "0")
  options = options.stringify_keys
  options["type"]     = "checkbox"
  options["value"]    = checked_value
  if options.has_key?("checked")
    cv = options.delete "checked"
    checked = cv == true || cv == "checked"
  else
    checked = self.class.check_box_checked?(value(object), checked_value)
  end
  options["checked"] = "checked" if checked
  add_default_name_and_id(options)
-  tag("input", options) << tag("input", "name" => options["name"], "type" => "hidden", "value" => options['disabled'] && checked ? checked_value : unchecked_value)
+  hidden = tag("input", "name" => options["name"], "type" => "hidden", "value" => options['disabled'] && checked ? checked_value : unchecked_value)
+  checkbox = tag("input", options)
+  hidden + checkbox
end

こういうときに、あちこちにあるのを全部直すということをしないために、ちゃんとヘルパにしておくのがBetterでしょうね。

■ mongrel_clusterを使う場合のlogger 01:21

production環境では、たいていはログのためにサーバが止まるのを避けるため、cronでrake log:clearしてるから、余り問題にされないのかもしれない。私は客先のイントラネットでRailsを使うことが多いので、ログを保存しておきたいケースが多い。

production環境ではmongrel_clusterやfastcgiを使って複数のRubyプロセスを立ち上げるのが普通だとおもうけど、Rails標準のロガーはそれに関して面倒は見てくれないので、production.logには時間が前後したログが記録されてしまう。

もっと問題なのは、ログローテーションが難しいということだ。

#environment.rb
config.logger = Logger.new(config.log_path, 14, 1048576)
config.log_level = :debug

とかやったところで、プロセスによってまちまちなログファイルを掴んでしまい、うまくいかない。

Rubyで完結したいならdRubyでやるだろうと思ったけど、すでに誰かが何らかの対策をしていると思ったし、探してみることにした。

最初に発見したのはlogrotateを使う方法だった。id:hiro-ueda:20080112:1200111879

mongrel_clusterは再起動に時間がかかるし、その間にアクセスがきたときに起動中のプロセスがあったら、Apacheにクラスタのメンバからはずされてしまうんではなかろうかとか、いろいろ不安だったので、別のを探すことにした。

次はSyslog路線で探してSyslogLoggerというgemを発見したものの、うまくいかなくて挫折した。

半日かかってようやくぴったりな情報を発見したら、やっぱりdRubyだった。DrbLogger

Rails2.0では以下の修正が必要だった。

#require 'active_support/clean_logger'
require 'active_support'

あとはlogserverのdaemon化と自動起動のための修飾を加えて、なんとかできた。

いわどんさんありがとう。

なお、今回はmongrel_clusterでやったのだけど、私はrailsというユーザで実行しているので、logserverもrailsで実行したかった。rootで実行するとローテーションの際にパーミッションが変わってしまうから。

方法としてはinit.dの起動スクリプト中でsudoするくらいしか思いつかなかったんだけど、

"sorry, you must have a tty to run sudo"というエラーになるので、ここを参考にして対策した。

あとlogserverでLogger.newした後にレベルを設定しとかないとデバッグ情報が出力されて遅くなってしまうのでINFO以上にした。

    if rails_env == 'production'
      @logger[rails_env].level = Logger::INFO
    else
      @logger[rails_env].level = Logger::DEBUG
    end
    @logger[rails_env]

ここまで書いてあれなんだけど、INFOはApacheのアクセスログをみればいい内容だから、ほんとはERROR以上で十分かもしれない。それだとログはほとんど増えないからそもそもログローテーションいらないじゃないか！

#environments/production.rb
config.log_level = :error

■ RailsでMySQLを使っているといつの間にかInternal Server Error 500になってる件 18:04

今までmod_fcgidでやっていたのだけど、最近mongrel_clusterを使うようになったので、いろいろ未経験のトラブルに遭遇する。

以前から「Lost connection to MySQL server...」とかいうエラーにはmysql_retry_lost_connectionというgemを使うという解決法は知っていたんだけど、どういう仕組みかまでは見てなかった。

Railsを使っていて「Lost connection to MySQL server during query」に遭遇したら - Hello, world! - s21g

最近立てたサーバでは上記のエラーはぜんぜん出てこないので、2.0では解決したのかなと思いつつgemを入れてなかった。最近気づいたのだけど、長時間放置していると、いつのまにか500エラーになってたので、ログを見てみると「MySQL server has gone away...」というエラーが残っていた。

メッセージが違うので、上のやつとは違うのだろうと思って、散々いろんなページを検索していたら、

こういうページに出会った。

http://wooga.drbacchus.com/rails-and-mysql-timeouts

それで、

# config/initializer/mysql-reconnect.rb

if ActiveRecord::Base.connection.adapter_name == 'MySQL'

ActiveRecord::Base.connection.instance_eval {@connection.reconnect = true}

end

なんてのを作ってみたんだけど、パフォーマンスに影響しないのかなと思ったので、ここに来て改めてmysql_retry_lost_connectionを見てみることにした。

          if reconnect_lost_connections and exception.message =~ /(Lost connection to MySQL server during query|MySQL server has gone away)/
            reconnect_lost_connections = false
            reconnect!
            retry
          elsif exception.message.split(":").first =~ /Packets out of order/

がーん！「MySQL server has gone away」にも対応してたんだね。

ただでさえ長い名前なのに恐縮ですが、こういう早とちりさんのために

mysql_retry_lost_connection_or_gone_away

に改名して下さい。うそです。

ActiveRecordオブジェクトのeql?は==に同じ。

==の定義は、

# File /usr/local/lib/ruby/gems/1.8/gems/activerecord-1.14.2/lib/active_record/base.rb, line 1567
      def ==(comparison_object)
        comparison_object.equal?(self) ||
          (comparison_object.instance_of?(self.class) && 
            comparison_object.id == id && 
            !comparison_object.new_record?)
      end

簡単に言うと、本当に同一のオブジェクトであるか、またはidが等しいものということ。