Rails でマイグレーションが失敗する恐怖から解放される感動的なすごい方法

開発中に rake db:migrate がエラーで中断しても、元に戻す方法がわからない。スキーマを書き換える SQL なんて覚えてない。失敗したのにスキーマのバージョンだけ上がったりする。

こういった問題を解決する、感動的なすごい方法があるのでは、と思って調べてたんだけど、見つけられなかった。

バックアップしてテスト環境で実行するのがよさそうです。普通です。

以下手順。環境は Rails 3 + MySQL

mysqldump を使って development DB を test にコピーする。バックアップ用の DB も作ってコピー。

$ mysqldump -u root myapp_development | mysql -u root myapp_test
$ mysqldump -u root myapp_development | mysql -u root myapp_backup

うっかり development を操作するのを防ぐため、 RAILS_ENV を test にセット。

$ export RAILS_ENV=test

うまくいくまで、migrate と mysqldump を繰り返す。

$ mysqldump -u root myapp_development | mysql -u root myapp_test
$ rake db:migrate RAILS_ENV=test
$ mysqldump -u root myapp_development | mysql -u root myapp_test
$ rake db:migrate RAILS_ENV=test
:

rollback もテストする。

$ mysqldump -u root myapp_development | mysql -u root myapp_test
$ rake db:migrate db:rollback RAILS_ENV=test
$ mysqldump -u root myapp_development | mysql -u root myapp_test
$ rake db:migrate db:rollback RAILS_ENV=test
:

test 環境でうまくいったら、お祈りして、 development 環境で実行する。development で失敗したらバックアップからコピーしてやり直す。おわり。



その他、使うかもしれない手口メモ。

リポジトリから db/schema.rb を復元して、クリーンな DB を作り直す。作業中、最新の migration でエラーが発生している場合、db:setup は実行できない。

git checkout db/schema.rb
rake db:drop db:create db:schema:load RAILS_ENV=test

最大のバージョン番号を消す SQL 。めんどくさい。

delete from schema_migrations where version = (select x.v from (select max(version) as v from schema_migrations) x);

Ruby の Dir.glob にブロックを渡すと、見つかった順に処理してくれる?

結論

Dir.globは見つけた順にブロックを評価するのかと思っていた。そんなことはなかった。

Dir.glob("**/*") {|file| ... }

は、ブロックに最初の1ファイル目を渡す前に、全ファイルを探す。

確認

環境は Mac + Ruby 1.8.7, 1.9.3。

確認に使ったスクリプト。

ディレクトリ2階層の下に計10万ファイルを作成し(create_many_files.rb)、1ファイル目を処理するまでにかかる時間と、全体を処理し終わる時間を

Dir.glob("**/*") {|file| ...}
Dir.glob("**/*").to_a.each  {|file| ...}

の2つで比較した(test.rb)。

$ ruby dirs.rb
1.9.3
---- block ----
first: 1.8421268463134766
last: 1.8548080921173096 200103
---- each ----
first: 1.8584198951721191
last: 1.8712561130523682  200103
---- block ----
first: 1.8612079620361328
last: 1.8742032051086426 200103
---- each ----
first: 1.8329567909240723
last: 1.8456907272338867  200103

:

$ rvm use 1.8.7
$ ruby dirs.rb
1.8.7
---- block ----
first: 1.71229195594788
last: 1.75075793266296 200103
---- each ----
first: 1.73645281791687
last: 1.77572989463806  200103
---- block ----
first: 1.73904895782471
last: 1.77682209014893 200103
---- each ----
first: 1.75206685066223
last: 1.79086184501648  200103

each でも ブロックを渡しても、差が見られない。

関係ないけど 1.9.3 より 1.8.7 のほうがちょっと速かった。

確認その2

dtraceを使って、プロセスがアクセスしたファイルを出力した。

dtrace oneliners より

# Files opened by process,
dtrace -n 'syscall::open*:entry { printf("%s %s",execname,copyinstr(arg0)); }'

最初の処理の前に何秒かsleepsするようにした。

$ test.rb 5 # 5秒スリープ

dtraceで、スリープする前に全ファイルが出力されるのを確認できる。ブロックでもeachでも同じだった。

まとめ

Dir.glob() {} は全ファイル探してからブロックを実行する。

見つけたファイルから順にブロックを評価するライブラリがどこかにはありそうだが、見つけられなかった。

余談

Dir.glob の順序は保証されない。

SourceTree の圧倒的な素晴らしさと致命的な欠点について。(修正済み)

(追記) 下記の問題点は、1.5で修正される予定とのことです。
(追追記) 濁点付きの検索はできないようですが、ログの問題は修正されていました。v1.5.3で確認。

https://img.skitch.com/20120510-mfpq1b6qj4a2f1x12bhq5wxafx.jpg
https://img.skitch.com/20120510-np5njbhset1m1dr66jbsb6pkux.jpg

SourceTree の UI は最高に素晴らしく、これまで見たどんなバージョン管理アプリケーションと比べても、次元が違う洗練されたユーザエクスペリエリンスが約束されており、有料になったら絶対買うんですが、いまは無料なので本当に感動的です。

でも一つだけ問題があって、、まともなコミットログが書けないんです……。

Firefox でこれ見ると、

こうなる。

https://img.skitch.com/20120502-xk1ss4wm3f5exp9mn1ksc91xi3.jpg

iTerm2 だとこう。*1

https://img.skitch.com/20120502-jy1pm569j8f2tq8qsgw9x71hhm.jpg

やめてー。やめてー。

いままで SourceTree でじゃんじゃんコミットしちゃった方はお気の毒です。あなたのコミットログぶっ壊れています。

ちなみにラテン文字でも問題おきています。すっごく微妙だけど。

https://img.skitch.com/20120503-8swsknnjdycekxyga37fib44mk.jpg

さらに悪いことに、つたない英語でバグレポートを書いたんですが、Won't Fix って言われちゃいました、、。

Unfortunately, this is unavoidable when calling external processes.

えー。。ほんとかよ。

おそらく Unicode Normalization っていう処理が正しく行われていないんだと思います。

コマンドラインはもちろん、GitHubクライアントもTowerも Precomposed な文字を出力できてて、SourceTree だけ互換性がない。このままだと困ると思うんだけどなあ、、。ちゃんと検索とか効くのかな。*2

よかったらVoteやコメントを、自分のよりもうちょっとマシなバグレポートをお願いします、、。

繰り返しになりますけど、SourceTree の UI は本当にいいと思うのでぜひ使ってみてください。自分はステージングとビューアとして使ってて、それだけでもかなりべんり。

*1:追記: この表示は iTerm2 ではなく tmux が原因だそうです。コメント参照。id:quintia さん、ありがとうございます。

*2:追記: 試してみたら、案の定、検索できませんでした。git コマンドでコミットした濁点付きのログが SourceTree の検索にヒットしなかった。逆に SourceTree のログが検索できないクライアントもあるはず。

Sinatra でアプリケーションログをファイルに書く方法。

Sinatra はじめて触ったんだけど、ログをファイルに書く方法がなかなかわからなかった。

ログを、ただファイルに書きたいのです。

結論

独自のミドルウェアで env['app.logger'] を設定し、アプリケーションのloggerメソッドをオーバーライドする。

参考

これに書いてある通りだった。面倒くさいー。

サンプル

以下でログがファイルに出力される。アクセスログとアプリケーションログを別のファイルに出力することもできる。

config.ru

Loggerを作ってミドルウェアに渡す。

require 'logger'
require 'sampleapp'
require 'applog'

logdir = File.dirname(__FILE__) + "/logs"
logger = ::Logger.new(logdir + '/app.log')

# CommonLoggerに渡すのに必要。
def logger.write(msg)
  self << msg
end

use AppLog, logger

# rackup(rack/server.rb)が設定するCommonLoggerは$stderrに、
# sinatra(sinatra/base.rb) が設定するCommonLoggerはenv['rack.errors'] に
# 出力しようとする。ファイルに書くため、独自に use する。
use Rack::CommonLogger, logger

run SampleApp
applog.rb

env['app.logger'] を設定するミドルウェア。app.loggerは自分が適当につけた名前。

class AppLog

  def initialize(app, logger)
    @app, @logger = app, logger
  end

  def call(env)
    env["app.logger"] = @logger
    @app.call(env)
  end

end
sampleapp.rb

アプリケーション。loggerメソッドは元々、request.loggerを返していて、request.loggerはenv['rack.logger']を返している。app.logger があればそちらを優先するようにする。

require 'sinatra/base'

class SampleApp < Sinatra::Base

  def logger
    env['app.logger'] || env['rack.logger']
  end

  get '/' do
    logger.info "OK"
    'OK'
  end

end

Rackのしくみ

アプリケーションをラップするミドルウェアがタマネギ状になってて、外から call(env) が順によばれていく。コアにあるアプリがenvからリクエストを得てレスポンスを返す。

ミドルウェアが call(env) で env['rack.logger'] を設定している。アプリはこのロガーを使いたいのだが、なぜか標準エラーにしか出力してくれない。

三種の logger

  • Rack::CommonLogger
  • Rack::Logger
  • Rack::NullLogger

このうち、下の2つが env['rack.logger'] を設定していた。Rack::Loggerだと下のような感じ。

    def call(env)
      logger = ::Logger.new(env['rack.errors'])
      logger.level = @level

      env['rack.logger'] = logger
      @app.call(env)
    end

NullLogger は何も出力しないロガー。

Rack::CommonLogger とは

Rack::CommonLogger はアプリケーションの実行後に、Apache形式でアクセスログを書くロガー。アプリケーションログと関係ない。

sinatra/base.rb と rack/server.rb に CommonLogger を設定する処理があり、環境によって、どちらか一方が使われる。

Sinatra が足す CommonLogger

Sinatra は base.rb の setup_default_middleware というメソッドでロガーを足している。

  • -E オプションで指定できる環境が development や deployment の場合は設定しない。
  • CommonLogger に引数は渡されておらず、デフォルトの env['rack.errors'] が出力先。
Rack が足す CommonLogger

rackup を実行すると、 rack/server.rb の buildapp メソッドが CommonLogger を追加する。

  • -E オプションで指定できる環境が development や deployment の場合に設定する。
  • Sinatra と条件が逆。Rack が設定しないなら Sinatra が設定する。
  • CommonLogger の引数は $stderr 。env['rack.errors'] ではない。
  • rackup が足す、その他のミドルウェアは self.logging_middleware と self.middleware メソッドのソースを参照。

Sinatra と Rack 、どっちにしてもエラー出力にログを出力する。

Rack::Logger とは

Rack::Logger は、標準の Logger を env['rack.logger'] に設定するミドルウェア。Logger の引数は env['rack.errors'] で固定。エラー出力にログを出力する。

Rack::Logger は、 Sinatra が追加していた。setup_default_middleware メソッドから呼ばれる setup_logging → setup_custom_logger メソッドを参照。enable :logging をしても、出力先は env['rack.errors'] になってしまう。

env['rack.errors'] を設定するのは誰なのか

自分の環境だと Thin が設定してた。サーバが設定する値。

の最後の回答で言われているように、標準エラー出力をファイルにリダイレクトする選択肢もあるようだが、もうちょっとマシな方法を探った。

CommonLogger が $stderr を使っているので、 evn['rack.errors'] を上書きするだけではダメだろうと思う。

ミドルウェアの呼ばれる順序とログ出力

独自のミドルウェアで env['rack.logger'] を入れ替えればいいのでは、と思ったのだが、config.ru にミドルウェアを足すと、call(env)される順序は、

  • rack/server.rb が設定した Rack::CommonLogger
  • config.ru が設定したミドルウェア
  • sinatra/base.rb が設定した Rack::Logger

になってしまう。自分が設定した rack.logger が Sinatra の Logger で上書きされてしまう。

結果として

アプリケーションでLoggerを直接使う。あるいは、上記サンプルのように、 app.logger を設定して loggerメソッドを上書きするのが、いくらかスマートだと思う。

CommonLogger はそのままだと使えないので、別に自前のをもう一個設定する。

追記

確認に使ったバージョンは以下のとおり。

  • Rack 1.4.1
  • Sinatra 1.3.2
  • Thin 1.3.1

やっぱり冷静に考えると rack.logger が使えないのはおかしいので、サーバで rack.errors を制御するのが、設計の意図なのかもしれない。ただ、現バージョンの rackup -D でデーモンとして起動する場合に、rack.errors を設定する方法はみつけられなかった。

PHP で h() を書くなら一緒に echo しよう。

名前が長い関数 htmlspecialchars() を h() と書けるようにすると便利、という話がある。

htmlspecialchars() なんて長い名前は絶対忘れるし、ENT_QUOTESだのUTF-8だのも書き忘れるに決まっている。

h() は CakePHP でも使われていて、いいと思う。いいと思うんだけど、もうちょっといける。

<?php 
/** 改善前のエスケープ関数 */
function h($str)
{
    return htmlspecialchars($str, ENT_QUOTES, 'UTF-8')
}

このようにエスケープした結果をreturnで返すと、エスケープと出力を離して書けてしまう。

$name = h($name);
:
// 長い長い処理の後に
:
<?php echo $name; // たしかエスケープ済だったかな ?>
<?php echo h($address); // こっちはエスケープしてなかったかも ?>

これだとぜったいエスケープし忘れる。もしくは二重にエスケープする。

エスケープが常に出力の直前になるように h() の中で echo も実行するといい。エスケープしていない(echoが直に書かれた)箇所を目立たせる結果にもなる。

<?php 
/**
 * HTMLの特殊文字をエスケープして結果を出力します。
 */
function h($str)
{
    echo htmlspecialchars($str, ENT_QUOTES, 'UTF-8');
}

次のように使う。

<?php h($name); ?>
<?php h($address); ?>

htmlspecialchars() を実行した文字列に対して更に何か加工するのは例外的なケースだが、よくあるのは改行を<br/>にする処理で、これは hbr() として定義する。

<?php 
/**
 * HTMLの特殊文字をエスケープして改行の前にbrタグを追加し、結果を出力します。
 */
function hbr($str)
{
    echo nl2br(htmlspecialchars($str, ENT_QUOTES, 'UTF-8'));
}

それ以外は頑張って htmlspecialchars() と書く、と言いたいけど、ENT_QUOTES、'UTF-8'を忘れそうなので、やはり関数を定義しておいたほうが安心かも。h() を使いたくなるように、名前は長めにする。

<?php 
/**
 * HTMLの特殊文字をエスケープして結果を返します。通常は h() を使います。
 */
function htmlescape($str)
{
    return htmlspecialchars($str, ENT_QUOTES, 'UTF-8');
}

配列をまとめてエスケープといった話はすっぱり忘れる。やるなら htmlescapeArray(array $array) を定義して、処理内容を明確にする。

参考

「出力の直前に」「例外なく」「エスケープしていることがわかるように」

セキュリティ云々以前に、プログラムの開発方法論として、できるだけ局所的な視点でコードの正当性を確認できるように書くのが、近代プログラミングの基本だ。つまり、このコード断片だけ見て、問題がないとわかるように書くべきである。
:
たとえば、echo を全面的に使用禁止として次のように書くのもよいだろう。

高木浩光@自宅の日記 - プログラミング解説書籍の脆弱性をどうするか, 「サニタイズ言うなキャンペーン」とは何か, ASPとかJSPとかPHPとかERBとか、逆だ..

PHP で何かを出力する際には,それが人の目に触れる形で表示されるかどうかにかかわらず,出力の直前に htmlspecialchars() を必ず通すようにしましょう。

セキュリティ上の配慮

以下の文字列をサニタイズする。サニタイズするタイミングは、データ受付時ではなく、HTML出力直前に例外なく行うこと。

セキュリティ指針/クロスサイトスクリプティング - ゼンド・ジャパン株式会社 技術情報コンテンツ

はまちちゃん先生の記事に触発されて書きました。

RFC のテキストページや日本語訳から IETF の HTML ページを開くブックマークレット。

Hatena::Let なんて素敵なサービスがあるのを今まで知らなかった。ので使ってみました。

URLのRFC番号っぽいのを探して IETF の HTML ページに移動します。例えば、

から

に移動します。

更新。IETF HTMLページにいるときは、「RFC (番号) 日本語」でGoogle検索するようにしました。これで日本語の一覧(Google結果)とHTMLページを行き来できます。あともうちょっとゆるく番号を探すようにしました。