Skip to content
This repository

column_attributes_test.rb test always cause Segmentation fault (core dumped) #162

Closed
yahonda opened this Issue April 23, 2012 · 10 comments

2 participants

Yasuo Honda Kubo Takehiro
Yasuo Honda
Collaborator

Whenever ActiveRecord master branch tested with Oracle enhanced adapter rails4 branch,
I've got a Segmentation fault (core dumped) .

-- Environment
ruby 1.9.3p194 (2012-04-20 revision 35410) [x86_64-linux]
Oracle 10gR2 on Linux(x86 32-bit)

This test successfully runs with postgresql, mysql, mysql2 and sqlite3 adapters. I've posted this issue here.

$ cd activerecord
$ ARCONN=oracle ruby -Itest test/cases/migration/column_attributes_test.rb 

Using oracle
Run options: --seed 60596

# Running tests:

E..SDEPRECATION WARNING: the object returned from `select_all` must respond to `column_types`. (called from first at /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:83)
/home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:46:in `block in find_by_sql'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/explain.rb:37:in `logging_query_plan'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:39:in `find_by_sql'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:174:in `exec_queries'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:164:in `block in to_a'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/explain.rb:37:in `logging_query_plan'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:163:in `to_a'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation/finder_methods.rb:319:in `find_first'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation/finder_methods.rb:70:in `first'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:83:in `first'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:68:in `find'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:6:in `find'
  test/cases/migration/column_attributes_test.rb:67:in `test_native_decimal_insert_manual_vs_automatic'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/gems/mocha-0.11.1/lib/mocha/integration/mini_test/version_230_to_262.rb:28:in `run'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/testing/setup_and_teardown.rb:29:in `block in run'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:354:in `_run__472795487047185378__setup__callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:346:in `__run_callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:79:in `run_callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/testing/setup_and_teardown.rb:28:in `run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `block in _run_suites'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `map'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `_run_suites'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:664:in `block in autorun'
DEPRECATION WARNING: the object returned from `select_all` must respond to `column_types`. (called from first at /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:83)
/home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:46:in `block in find_by_sql'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/explain.rb:37:in `logging_query_plan'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:39:in `find_by_sql'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:174:in `exec_queries'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:164:in `block in to_a'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/explain.rb:37:in `logging_query_plan'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation.rb:163:in `to_a'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation/finder_methods.rb:319:in `find_first'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/relation/finder_methods.rb:70:in `first'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:83:in `first'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-a3c521fde11a/lib/active_record_deprecated_finders/relation.rb:68:in `find'
  /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/querying.rb:6:in `find'
  test/cases/migration/column_attributes_test.rb:82:in `test_native_decimal_insert_manual_vs_automatic'
  /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/gems/mocha-0.11.1/lib/mocha/integration/mini_test/version_230_to_262.rb:28:in `run'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/testing/setup_and_teardown.rb:29:in `block in run'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:354:in `_run__472795487047185378__setup__callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:346:in `__run_callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/callbacks.rb:79:in `run_callbacks'
  /home/yahonda/Dropbox/git/rails/activesupport/lib/active_support/testing/setup_and_teardown.rb:28:in `run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:787:in `block in _run_suite'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `map'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:780:in `_run_suite'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `block in _run_suites'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `map'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:770:in `_run_suites'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:746:in `_run_anything'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:909:in `run_tests'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:896:in `block in _run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `each'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:895:in `_run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:884:in `run'
  /home/yahonda/.rvm/rubies/ruby-1.9.3-p194/lib/ruby/1.9.1/minitest/unit.rb:664:in `block in autorun'
.Segmentation fault (core dumped)
Yasuo Honda
Collaborator

I tried to narrow down this issue and found several.

The last sql statement at debug.log looks come from the test_native_types test.

  SQL (19.1ms)  INSERT INTO "TEST_MODELS" ("AGE", "BIO", "BIRTHDAY", "CREATED_AT", "FAVORITE_DAY", "FIRST_NAME", "HEIGHT", "ID", "LAST_NAME", "MALE", "MOMENT_OF_TRUTH", "UPDATED_AT", "WEALTH") VALUES (:a1, :a2, :a3, :a4, :a5, :a6, :a7, :a8, :a9, :a10, :a11, :a12, :a13)  [["age", 18], ["bio", "I was born ...."], ["birthday", 1994-04-24 04:34:59 -0400], ["created_at", 2012-04-24 08:34:59 UTC], ["favorite_day", 2012-04-14 04:34:59 -0400], ["first_name", "bob"], ["height", #<BigDecimal:3976e88,'0.178E1',18(45)>], ["id", 10000], ["last_name", "bobsen"], ["male", true], ["moment_of_truth", 1782-10-10 21:40:18 UTC], ["updated_at", 2012-04-24 08:34:59 UTC], ["wealth", #<BigDecimal:42411a8,'0.1234567890 1234567890 0123456789E20',45(45)>]]

Then skipping this test does not cause any segmentation fault.

diff --git a/activerecord/test/cases/migration/column_attributes_test.rb b/activerecord/test/cases/migration/column_attributes_test.rb
index 040445e..dec04db 100644
--- a/activerecord/test/cases/migration/column_attributes_test.rb
+++ b/activerecord/test/cases/migration/column_attributes_test.rb
@@ -115,6 +115,7 @@ module ActiveRecord
       end

       def test_native_types
+        skip "TO SEE IF THIS TEST CORE DUMPS" if current_adapter?(:OracleAdapter)
         add_column "test_models", "first_name", :string
         add_column "test_models", "last_name", :string
         add_column "test_models", "bio", :text

I'm going to see if this error happens with Rails 3.2.x or other released version of Rails.

Yasuo Honda
Collaborator

It does not reproduce with Rails 3.2.3. Still looking for the cause.

Yasuo Honda
Collaborator

After applying the change suggested here,
more information generated https://gist.github.com/2489557

Still hard to see what is the cause.

Kubo Takehiro
kubo commented April 25, 2012

I reproduced the issue and found a workaround. But I doubt whether it is the real solution.
What I did is adding "prefetch_rows: 1" to git/rails/activerecord/test/config.yml as follows:

  oracle:
     arunit:
       adapter: oracle_enhanced
       database: <%= ENV['ARUNIT_DB_NAME'] || 'orcl' %>
       username: <%= ENV['ARUNIT_USER_NAME'] || 'arunit' %>
       password: <%= ENV['ARUNIT_PASSWORD'] || 'arunit' %>
       emulate_oracle_adapter: true
       prefetch_rows: 1
     arunit2:
       adapter: oracle_enhanced
       database: <%= ENV['ARUNIT_DB_NAME'] || 'orcl' %>
       username: <%= ENV['ARUNIT2_USER_NAME'] || 'arunit2' %>
       password: <%= ENV['ARUNIT2_PASSWORD'] || 'arunit2' %>
       emulate_oracle_adapter: true
       prefetch_rows: 1

This may be an issue of prefetch buffer handling in Oracle library layer.

Yasuo Honda
Collaborator

Thank you for your investigation. I tried "prefetch_rows: 1" and the errors changed to "SystemStackError: stack level too deep". If I understand correctly, you meant this setting did workaround without any SystemStackError(s).

$ ARCONN=oracle ruby -Itest test/cases/migration/column_attributes_test.rb
Using oracle
Run options: --seed 11716

# Running tests:

...SEES

Finished tests in 0.926780s, 7.5530 tests/s, 8.6320 assertions/s.

  1) Error:
test_native_decimal_insert_manual_vs_automatic(ActiveRecord::Migration::ColumnAttributesTest):
SystemStackError: stack level too deep
    /home/yahonda/.rvm/gems/ruby-1.9.3-p194@railsmaster/bundler/gems/active_record_deprecated_finders-df10a70b63aa/lib/active_record_deprecated_finders/base.rb:56

  2) Error:
test_native_types(ActiveRecord::Migration::ColumnAttributesTest):
SystemStackError: stack level too deep
    /home/yahonda/Dropbox/git/rails/activerecord/lib/active_record/scoping.rb:126

7 tests, 8 assertions, 0 failures, 2 errors, 2 skips
$ 

My environment is.
ruby 1.9.3p194 (2012-04-20 revision 35410) [x86_64-linux]
Oracle 11gR2 11.2.0.3 64-bit ( both client/server run on the same box)

Yasuo Honda
Collaborator

Now this workaround works! No software version except for git fetch upstream and git merge upstream/master.

(Update: This comment was wrong, I did modify the test column_attributes_test.rb script to skip the test_native_types test)

Kubo Takehiro
kubo commented April 26, 2012

I found another workaround.
Change :statement_cache_size to nil in ruby-oci8-2.1.1/lib/oci8/properties.rb.

  @@properties = {
    :length_semantics => :byte,
    :bind_string_as_nchar => false,
    :float_conversion_type => :ruby,
    :statement_cache_size => nil,   # Change this line
  }

Hmm, I may disable statement caching in OCI at the next ruby-oci8 release.

My environment is.
ruby 1.9.3p194 (2012-04-20 revision 35410) [x86_64-linux]
Oracle XE 10.2.0.1.0 (32-bit) (server)
Oracle instant client 11.2.0.3.0 (64-bit)
Oracle instant client 11.2.0.2.0 (64-bit)
Oracle instant client 11.1.0.7.0 (64-bit)

Yasuo Honda
Collaborator

My previous update was wrong. prefetch_rows: 1 is not a workaround in my environment. https://gist.github.com/2501084
Let me try if :statement_cache_size => nil works.

Yasuo Honda
Collaborator

This workaround works with Oracle 11.2.0.3 client/server (64-bit on Linux x64). Really appreciated.

    :statement_cache_size => nil

This error was found while testing Rails master branch and Oracle enhanced adapter rails4 branch, which is still in beta. therefore I'm okay to implement this workaround for a while.

Yasuo Honda
Collaborator

No segmentation faults with ruby-oci8 2.1.2. Thanks!

Yasuo Honda yahonda closed this April 28, 2012
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.