Bug #4178: test/rubygems/gemutilities.rb で、よくわからない ArgumentError

• Status: Closed
• Assignee: -
• Target version: -
• ruby -v: ruby 1.9.3dev (2010-12-21 trunk 30285) [x86_64-freebsd8.2]

[metanest (Makoto Kishimoto)]

=begin
（bisectによれば）trunk の r29064 以降、test-all でたまに発生しているのですが、
（たとえば http://mrkn.jp/chkbuild/ruby-trunk/log/20100925T163004Z.diff.html.gz
) Error:
+test_install_ignore_dependencies(TestGemDependencyInstaller):
+ArgumentError: wrong number of arguments (0 for 1)

• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/gemutilities.rb:276:in `block (2 levels) in util_build_gem'
• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/gemutilities.rb:275:in `block in util_build_gem'
• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/gemutilities.rb:268:in `chdir'
• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/gemutilities.rb:268:in `util_build_gem'
• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/gemutilities.rb:293:in `util_gem'
• /Users/chkbuild/build/ruby-trunk//ruby/test/rubygems/test_gem_dependency_installer.rb:50:in `setup'
• ./test/runner.rb:17:in `'
  ）
  こんな感じで、test/rubygems/gemutilities.rb で、よくわからない ArgumentError が起きます。
  TESTS に --gc-stress を付けたり、以下のようなスクリプトでほぼ100%再現します。

require_relative "test/rubygems/gemutilities"
class TestHoge < RubyGemTestCase
def setup
super
GC.stress = true
util_setup_fake_fetcher
end

def test_hoge
end
end
=end

[metanest (Makoto Kishimoto)]

=begin
もうちょっと小さくしてみました。以下のようなスクリプトで手元では再現します。

require "rubygems/package.rb"

open("/dev/null", "wb"){|io|
Gem::Package::TarOutput.open(io){}
GC.stress = true
Gem::Package::TarOutput.open(io){}
}

手元の ruby 1.9 trunk で実行すると以下のようになります。

/usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:70:in metadata=': wrong number of arguments (0 for 1) (ArgumentError) from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:75:in block (3 levels) in add_gem_contents'
from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_writer.rb:83:in new' from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:67:in block (2 levels) in add_gem_contents'
from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:65:in wrap' from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:65:in block in add_gem_contents'
from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_writer.rb:113:in add_file' from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:63:in add_gem_contents'
from /usr/local/lib/ruby/1.9.1/rubygems/package/tar_output.rb:31:in open' from foo.rb:6:in block in '
from foo.rb:3:in open' from foo.rb:3:in '

tar_output.rb の 75 行目にあるのは reader の "metadata" メソッドの呼び出しの
はずなのに、なぜか writer の "metadata=" メソッドの呼び出しにすりかわっています。
=end

[wanabe (_ wanabe)]

=begin
miniruby でも確認できるように縮めました。
:foo が 5 回表示されるはずが、:foo が 2 回表示された後は :bar と :foo が交互に表示されました。

5.times do
GC.stress = !GC.stress
obj = Object.new
def obj.foo() p :foo end
def obj.bar() p :bar end
obj.foo
end

r29063 をリバートするとこの現象は起きなくなりました。なぜかはわかりませんでした。
また、i386-mingw32 および i686-linux では再現せず x64-mingw64 で再現しました。
なにか 64-bit 環境に関係があるのかもしれません。
=end

[wanabe (_ wanabe)]

=begin
すみません、下記のパッチで症状が治まるか確認して頂けないでしょうか。
rb_iseq_clone で作られた iseqval が最適化でスタックに置かれず、GC されてしまっているのではないかと思います。

diff --git a/vm.c b/vm.c
index 015456b..4a80f5d 100644
--- a/vm.c
+++ b/vm.c
@@ -1838,6 +1838,7 @@ vm_define_method(rb_thread_t *th, VALUE obj, ID id, VALUE iseqval,

  if (miseq->klass) {
     iseqval = rb_iseq_clone(iseqval, 0);

• RB_GC_GUARD(iseqval);
  GetISeqPtr(iseqval, miseq);
  }

=end

[metanest (Makoto Kishimoto)]

=begin
きしもとです

このエントリに登録したスクリプトで試しましたが、治まりました。

make test-all TESTS='--gc-stress -v rubygems' の実行を待っているのですが
終わりそうにないので、とりあえず報告まで。

On Wed, 29 Dec 2010 19:31:05 +0900
_ wanabe [e-mail] wrote:

チケット #4178 が更新されました。 (by _ wanabe)

すみません、下記のパッチで症状が治まるか確認して頂けないでしょうか。
rb_iseq_clone で作られた iseqval が最適化でスタックに置かれず、GC されてしまっているのではないかと思います。

diff --git a/vm.c b/vm.c
index 015456b..4a80f5d 100644
--- a/vm.c
+++ b/vm.c
@@ -1838,6 +1838,7 @@ vm_define_method(rb_thread_t *th, VALUE obj, ID id, VALUE iseqval,

 if (miseq->klass) {
    iseqval = rb_iseq_clone(iseqval, 0);

• RB_GC_GUARD(iseqval);
  GetISeqPtr(iseqval, miseq);
  }

---

http://redmine.ruby-lang.org/issues/show/4178

=end

[wanabe (_ wanabe)]

• Status changed from Open to Closed
• % Done changed from 0 to 100

=begin
This issue was solved with changeset r30432.
Makoto, thank you for reporting this issue.
Your contribution to Ruby is greatly appreciated.
May Ruby be with you.

=end