Bugs / Issues: Browse | Submit New | Admin

[#24267] SIGSEGV or SIGBUS in garbage collector

Date:
2009-03-03 02:38
Priority:
3
Submitted By:
Vlad Romascanu (vladr)
Assigned To:
Nobody (None)
Category:
None
State:
Open
Summary:
SIGSEGV or SIGBUS in garbage collector

Detailed description
========== version =============
$ uname -a
Linux test 2.6.24-19-xen #1 SMP Wed Aug 20 21:08:51 UTC 2008 x86_64 GNU/Linux
$ /opt/ruby-enterprise-1.8.6-20090113/bin/ruby --version
ruby 1.8.6 (2008-08-08 patchlevel 286) [x86_64-linux]
$ gem list --local passenger
*** LOCAL GEMS ***
passenger (2.0.6)
$ passenger-config --version
2.0.6
$ passenger-config --root
/opt/ruby-enterprise-1.8.6-20090113/lib/ruby/gems/1.8/gems/passenger-2.0.6
$ apache2 -v
Server version: Apache/2.2.8 (Ubuntu)
Server built:   Jun 25 2008 13:54:43
$ tail -3 /var/log/apache2/error.log
/opt/ruby-enterprise-1.8.6-20090113/lib/ruby/gems/1.8/gems/aws-s3-0.5.1/lib/aws/s3/extensions.rb:291: [BUG] Bus Error
ruby 1.8.6 (2008-08-08) [x86_64-linux]


========== passenger cfg ======
LoadModule passenger_module
/opt/ruby-enterprise-1.8.6-20090113/lib/ruby/gems/1.8/gems/passenger-2.0.6/ext/apache2/mod_passenger.so
PassengerRoot /opt/ruby-enterprise-1.8.6-20090113/lib/ruby/gems/1.8/gems/passenger-2.0.6
PassengerRuby /opt/ruby-enterprise-1.8.6-20090113/bin/ruby
PassengerMaxInstancesPerApp 2
RailsMaxPoolSize 2
RailsEnv production
RailsRuby /opt/ruby-enterprise-1.8.6-20090113/bin/ruby
PassengerDefaultUser www-data


========== corefile ===========
email me! ntvdm@hotmail.com (35MB compressed)


========== backtrace ===========
Program received signal SIGBUS, Bus error.
[Switching to Thread 0x7fa1732c86f0 (LWP 6481)]
0x00000000004752f7 in st_foreach (table=0x1fe49d8, func=0x430a30 <mark_entry>, arg=1) at st.c:487
487                 retval = (*func)(ptr->key, ptr->record, arg);
(gdb) bt
#0  0x00000000004752f7 in st_foreach (table=0x1fe49d8, func=0x430a30 <mark_entry>, arg=1) at st.c:487
#1  0x0000000000430b01 in mark_locations_array (x=0x7fff7b2a0748, n=27724) at gc.c:1133
#2  0x0000000000430cae in garbage_collect () at gc.c:1980
#3  0x0000000000431d17 in ruby_xmalloc (size=1048577) at gc.c:133
#4  0x0000000000477917 in str_new (klass=<value optimized out>, ptr=0x0, len=1048576) at string.c:92
#5  0x00000000004781b9 in rb_tainted_str_new (ptr=0x71616e6f6d2e6e69 <Address 0x71616e6f6d2e6e69 out of bounds>,
len=1) at string.c:123
#6  0x000000000043baca in io_read (argc=<value optimized out>, argv=<value optimized out>, io=114458320)
at io.c:1475
#7  0x000000000041ce59 in rb_call0 (klass=10089120, recv=114458320, id=7337, oid=7337, argc=1, argv=0x7fff7b2a3420,
body=0x99e710,
    flags=<value optimized out>) at eval.c:5870
#8  0x000000000041d187 in rb_call (klass=10089120, recv=114458320, mid=7337, argc=1, argv=0x7fff7b2a3420, scope=0,
self=114453960) at eval.c:6117
#9  0x00000000004187d1 in rb_eval (self=114453960, n=<value optimized out>) at eval.c:3490
#10 0x0000000000419bac in rb_eval (self=<value optimized out>, n=<value optimized out>) at eval.c:3675
(gdb) info proc
process 6481
cmdline = '...'
cwd = '/var/www/...'
exe = '/opt/ruby-enterprise-1.8.6-20090113/bin/ruby'
(gdb) gcore /tmp/core.ruby.6481
Saved corefile /tmp/core.ruby.6481


========== trigger ===========
This appears to be triggered by large strings (1MB) of memory being allocated in a tight loop while reading from a file
(Rails w/ Passenger, see versions above, 'production' environment.)

Ticket #22456 appears to be another instance of this error.

In my particular instance, the behavior is triggered from
/opt/ruby-enterprise-1.8.6-20090113/lib/ruby/gems/1.8/gems/aws-s3-0.5.1/lib/aws/s3/extensions.rb:291

291        while s = f.read(chunk_size)
292          sock.write s
293        end

where f is a File, and chunk_size=1048576.  The crash will occur around the 15th iteration.

The crash will NOT occur if:

 - Rails is configured in development mode
 - a logging statement (::RAILS_DEFAULT_LOGGER.warn(...)) is inserted just before line 291
 - the loop is rewritten to be less demanding on the GC as follows:

291        s = String.new # File.read reuses buffer, GC no longer crashes
292        while f.read(chunk_size, s)
293          sock.write s
294        end


========== reproducibility ===========
On my machine it was reproducible 95% of the time.
Has also occurred on a 32-bit production XEN VM (SIGSEGV instead of SIGBUS).

Add A Comment: Notepad

Please login


Followup

Message
Date: 2009-03-03 03:13
Sender: Vlad Romascanu

Just want to confirm that this also happens with the latest 
publicly downloadable REE (20090201):

$ /opt/ruby-enterprise-1.8.6-20090201/bin/ruby --version
ruby 1.8.6 (2008-08-08 patchlevel 286) [x86_64-linux]
$ passenger-config --version
2.0.6
$ passenger-config --root
/opt/ruby-enterprise-1.8.6-
20090201/lib/ruby/gems/1.8/gems/passenger-2.0.6
$ tail -3 /var/log/apache2/error.log
/opt/ruby-enterprise-1.8.6-
20090201/lib/ruby/gems/1.8/gems/aws-s3-
0.5.1/lib/aws/s3/extensions.rb:291: [BUG] Bus Error
ruby 1.8.6 (2008-08-08) [x86_64-linux]






Program received signal SIGBUS, Bus error.
[Switching to Thread 0x7f32f7bc56f0 (LWP 22573)]
0x00000000004752f7 in st_foreach (table=0x1d57000, 
func=0x430a30 <mark_entry>, arg=1) at st.c:487
487                 retval = (*func)(ptr->key, ptr->record,
arg);
(gdb) bt
#0  0x00000000004752f7 in st_foreach (table=0x1d57000, 
func=0x430a30 <mark_entry>, arg=1) at st.c:487
#1  0x0000000000430b01 in mark_locations_array 
(x=0x7fffffb9e048, n=27724) at gc.c:1133
#2  0x0000000000430cae in garbage_collect () at gc.c:1980
#3  0x0000000000431d17 in ruby_xmalloc (size=1048577) at 
gc.c:133
#4  0x0000000000477917 in str_new (klass=<value optimized 
out>, ptr=0x0, len=1048576) at string.c:92
#5  0x00000000004781b9 in rb_tainted_str_new 
(ptr=0x71616e6f6d2e6e69 <Address 0x71616e6f6d2e6e69 out of 
bounds>, len=1) at string.c:123
#6  0x000000000043baca in io_read (argc=<value optimized 
out>, argv=<value optimized out>, io=113930640)
at io.c:1475
#7  0x000000000041ce59 in rb_call0 (klass=10089120, 
recv=113930640, id=7337, oid=7337, argc=1, 
argv=0x7fffffba0d20, body=0x99e710,
    flags=<value optimized out>) at eval.c:5870
#8  0x000000000041d187 in rb_call (klass=10089120, 
recv=113930640, mid=7337, argc=1, argv=0x7fffffba0d20, 
scope=0, self=113926280) at eval.c:6117
#9  0x00000000004187d1 in rb_eval (self=113926280, n=<value 
optimized out>) at eval.c:3490
#10 0x0000000000419bac in rb_eval (self=<value optimized 
out>, n=<value optimized out>) at eval.c:3675
(gdb) gcore /tmp/core.ruby_ee_20090201.22573
Saved corefile /tmp/core.ruby_ee_20090201.22573



Core file for 20090201 is also available if requested 
(25MB).

Attached Files:

Name Description Download
No Files Currently Attached

Changes:

No Changes Have Been Made to This Item