Backport #3313: object has the wrong type during long-running test

• Status: Closed
• Assignee: -

[coatl (caleb clausen)]

=begin
To reproduce this bug:
gem install sequence
cd /tmp #or some other suitable dir
git clone git://github.com/coatl/rubylexer.git
cd rubylexer
ruby -Ilib test/code/heredoc_blast_test.rb
#now wait, up to 4 hours for the test to either complete or fail.

This runs the same test (parsing heredocuments with rubylexer) over and over. Very rarely, the test will fail, and I don't know why. It actually fails inside sequence, a support library for rubylexer. The stack trace indicates that in notify_change on line 700 of sequence.rb, @change_listeners contains an object of the wrong type (an Array instead of a Sequence). The only place where things are put into @change_listeners is in on_change_notify, just above notify_change. That method carefully checks that the item inserted into @change_listeners is of the right type (responds to change_notification) before adding it.

@change_listeners is a WeakRefSet, and thus weak references are involved. It's possible that I'm not handling those weak references correctly in weakrefset.rb, but I've been over that code repeatedly and it seems to be correct. define_finalizer is used to keep the WeakRefSet notified when one of its members is gc'd, and the WeakRefSet then dutifully removes the dying object.

I'm reporting this for 1.8.7, but I've seen it on (fairly recent vintages of) 1.8.6 as well. It may well also be a problem for 1.9 versions of ruby, but when I try to test for this problem on 1.9, I run straight into bug #2502, which prevents the test from running long enough to see this problem.

I'm sorry for all the code and time needed to reproduce this one. I did try to boil it down to a smaller case, but with only slight success.

Here's the erroneous output.

ruby -Ilib test/code/heredoc_blast_test.rb
Loaded suite test/code/heredoc_blast_test
Started
Eskipping testcase_10; not legal
.skipping testcase_11; not legal
.Eskipping testcase_2; not legal
.skipping testcase_3; not legal
.skipping testcase_4; not legal
.skipping testcase_5; not legal
.skipping testcase_6; not legal
.skipping testcase_7; not legal
.skipping testcase_8; not legal
.skipping testcase_9; not legal
.
Finished in 956.663375 seconds.

1. Error:
   testcase_0__(LexerTests):
   NoMethodError: undefined method change_notification' for [-611168978]:Array /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence.rb:700:in notify_change'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:99:in each' /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:87:in each_key'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:87:in each' /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence.rb:699:in notify_change'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/list.rb:258:in modify' ./lib/rubylexer.rb:2324:in here_header'
   ./lib/rubylexer.rb:2387:in lessthan__no_offset' (eval):6:in lessthan'
   ./lib/rubylexer/charhandler.rb:86:in send' ./lib/rubylexer/charhandler.rb:86:in go'
   ./lib/rubylexer/rulexer.rb:92:in rulexer_get1token' ./lib/rubylexer.rb:292:in get1token'
   (eval):145:in testcase_0__' (eval):3:in times'
   (eval):3:in `testcase_0__'

2. Error:
   testcase_1__(LexerTests):
   NoMethodError: undefined method change_notification' for [-611406058]:Array /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence.rb:700:in notify_change'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:99:in each' /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:87:in each_key'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/weakrefset.rb:87:in each' /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence.rb:699:in notify_change'
   /var/lib/gems/1.8/gems/sequence-0.2.3/lib/sequence/list.rb:258:in modify' ./lib/rubylexer.rb:2324:in here_header'
   ./lib/rubylexer.rb:2387:in lessthan__no_offset' (eval):6:in lessthan'
   ./lib/rubylexer/charhandler.rb:86:in send' ./lib/rubylexer/charhandler.rb:86:in go'
   ./lib/rubylexer/rulexer.rb:92:in rulexer_get1token' ./lib/rubylexer.rb:292:in get1token'
   (eval):294:in testcase_1__' (eval):152:in times'
   (eval):152:in `testcase_1__'

12 tests, 0 assertions, 0 failures, 2 errors
=end

[mame (Yusuke Endoh)]

=begin
Hi,

2010/5/18 caleb clausen [e-mail]:

I'm reporting this for 1.8.7, but I've seen it on (fairly recent vintages of) 1.8.6 as well. It may well also be a problem for 1.9 versions of ruby, but when I try to test for this problem on 1.9, I run straight into bug #2502, which prevents the test from running long enough to see this problem.

Unfortunately, #2502 is decided as WONTFIX for 1.9.2.
So this issue cannot be reproducible in 1.9.2.

I think it would be good to investigate this issue in 1.8 subproject.
So I move this ticket to 1.8. If the bug is figured out and may be
also reproducible in 1.9, the fix will be backported to 1.9.

--
Yusuke Endoh [e-mail]
=end

[jeremyevans0 (Jeremy Evans)]

• Tracker changed from Bug to Backport
• Project changed from Ruby 1.8 to Backport187
• Description updated (diff)
• Status changed from Open to Closed
• ruby -v deleted (ruby 1.8.7 (2008-08-11 patchlevel 72) [i486-linux])