複数プロセスからのファイル書き込み（追記の場合）における注意点

実行条件

１００プロセス同時に５０００行の書き込みを行う。

テストコード

100.times do
  pid = fork do
    open(File.join(File.dirname(File.expand_path(__FILE__)),"aaaaaaaaa.log"), 'a') do |f|
      f.sync = true # syncしないと文字列が途中でおかしくなる場合がある。
      5000.times do
        time = Time.now
        f.write "[#{time.strftime("%Y/%m/%d %H:%M:%S")}][#{$$}]test\n" #OK
        #f.puts "[#{time.strftime("%Y/%m/%d %H:%M:%S")}][#{$$}]test"   #NG
        #f.puts "[#{time.strftime("%Y/%m/%d %H:%M:%S")}][#{$$}]test\n" #これはOK
      end
    end
  end
  Process.detach(pid)
end

気をつけること

• syncする
• putsは使わないでwriteを使う
• flockはしなくても問題なさそうでした(rubyの標準Logger,railsのBufferedLoggerもしてません)
  • 但しローリングをする場合にはflock使うように改良しないとだめでしょうけど。
  • OS依存しそうな気もするので念のため自分の環境でも確認したほうがよいと思います。私はCentOS 5.2で確認しました。

railsのLogは？

ちゃんと上記対策やってましたので問題なく複数プロセスで使っていいと思います。
これ調べるまで少し不安な部分がありましたけど安心しました(^^;

putsは使わないでwriteを使う理由

どうやら本文と改行を別々に書きこんでるみたいです。
そのため下記のような症状が出ます。

２行のはずが１行にまとまってしまったパターン

[2009/11/17 16:45:48][32628]test[2009/11/17 16:45:48][32626]test

上記で消えた改行がよそにいって１行空いてしまうパターン

[2009/11/17 16:45:46][32614]test
[2009/11/17 16:45:46][32614]test

[2009/11/17 16:45:46][32612]test
[2009/11/17 16:45:46][32612]test

(たまにあるぐらいです、よく中身を見ましょう。大体１０行ぐらいでしょうか。)

File#putsのソースを見て確認しました。（これは1.8.6のですが現時点の最新版のruby1.9.1-p243でも同様でした）
io.c

rb_io_puts(argc, argv, out)
    int argc;
    VALUE *argv;
    VALUE out;
{
    int i;
    VALUE line;

    /* if no argument given, print newline. */
    if (argc == 0) {
	rb_io_write(out, rb_default_rs);
	return Qnil;
    }
    for (i=0; i<argc; i++) {
	if (NIL_P(argv[i])) {
	    line = rb_str_new2("nil");
	}
	else {
	    line = rb_check_array_type(argv[i]);
	    if (!NIL_P(line)) {
		rb_protect_inspect(io_puts_ary, line, out);
		continue;
	    }
	    line = rb_obj_as_string(argv[i]);
	}
	rb_io_write(out, line); // 本文を書き込んでる
	if (RSTRING(line)->len == 0 ||
            RSTRING(line)->ptr[RSTRING(line)->len-1] != '\n') {
	    rb_io_write(out, rb_default_rs); // 改行がない場合に改行を書き込んでる
	}
    }

    return Qnil;
}

syncをする理由

下記の症状になります。

文字の途中に混ざっちゃいます。
[2009/11/17 16[2009/11/17 16:57:22][318]test

(たまにあるぐらいです、よく中身を見ましょう。大体５行ぐらいでしょうか。)

実行環境

CentOS 5.2
ruby (1.8.6 p287)