Help us understand the problem. What is going on with this article?

Rubyのparallelで並列処理するときにputsでLog出しするときに注意すること

More than 1 year has passed since last update.

TL;DR (長い3行で)

・parallel使って並列処理させるときにputsで標準出力にLog出しすると,
・行末の改行位置が正しく表示されない.(改行がされなかったり,2回改行されたり)
・putsの自動改行挿入によるものなので,print("**\n")puts("**\n")のように明示的に改行する.

何が困るか

Log出ししてる処理をparallelで並列化するときに,↓のようなCodeを書いたとします.

def func(i)
  puts "#### Function in Multi Thread : index=#{i}"
end

Parallel.each(1..1000, in_threads: 8) { |i|
  func(i)
}

端末に表示されるLogの期待値は ↓ だと思います.
ok.png

しかし,実際には ↓ のように改行位置が意図しないものになります.
ng.png

なんでこうなる?

Kernel.#puts の仕様書によると,
https://docs.ruby-lang.org/ja/2.4.0/method/Kernel/m/puts.html

引数と改行を順番に 標準出力 $stdout に出力します。

とのこと.”引数と改行を順番に”.

Kernel#putsのソースを確認するために,
pryshow-source putsすると,

From: io.c (C Method):
Owner: Kernel
Visibility: private
Number of lines: 8

static VALUE
rb_f_puts(int argc, VALUE *argv, VALUE recv)
{
    if (recv == rb_stdout) {
        return rb_io_puts(argc, argv, recv);
    }
    return rb_funcall2(rb_stdout, rb_intern("puts"), argc, argv);
}

`rb_io_puts'が実体のようなので,Rubyのソースコードで検索すると ↓ のコードが出てきます.
https://github.com/ruby/ruby/blob/trunk/io.c#L7573

rb_io_puts(int argc, const 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 (RB_TYPE_P(argv[i], T_STRING)) {
        line = argv[i];
        goto string;
    }
    if (rb_exec_recursive(io_puts_ary, argv[i], out)) {
        continue;
    }
    line = rb_obj_as_string(argv[i]);
      string:
    rb_io_write(out, line); // 引数の書き出し
    if (RSTRING_LEN(line) == 0 ||
            !rb_str_end_with_asciichar(line, '\n')) {
        rb_io_write(out, rb_default_rs); // '\n'が無いときにrb_default_rs(== '\n')を追加で出力
    }
    }

    return Qnil;
}

↓ こちらの解説も参考にさせていただきましたが,putsのnative実装の中で2回のwriteに分けて処理されていて,その間排他制御がされていない模様.
http://ode.hatenadiary.jp/entry/20091117/1258445186

こうすればOK

文字列終端に'\n'が無ければ\nをwriteする処理を黙らせればいいので,
puts("**\n")
のように明示的に改行を入れるか,
print("**\n")
を使えば期待どおりのLogが出力されます.

---///

Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away