Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Many failures in Sequel tests on [RuntimeError] exception expected, not Class: <NoMethodError> Message: <"undefined method `[]' for nil:NilClass"> #2993

Closed
deepj opened this Issue May 27, 2015 · 10 comments

Comments

Projects
None yet
4 participants
@deepj
Copy link

deepj commented May 27, 2015

There are no issues under JRuby 1.7.20. But under JRuby 9k occurs many failures due to the following error (please, see Travis also: https://travis-ci.org/jeremyevans/sequel/jobs/64145749):

 1) Failure:
Database#transaction with savepoints#test_0009_should issue ROLLBACK if an exception is raised, and re-raise [/home/travis/build/jeremyevans/sequel/spec/core/database_spec.rb:1117]:
[RuntimeError] exception expected, not
Class: <NoMethodError>
Message: <"undefined method `[]' for nil:NilClass">
---Backtrace---
/home/travis/build/jeremyevans/sequel/lib/sequel/database/transactions.rb:336:in `transaction_finished?'
/home/travis/build/jeremyevans/sequel/lib/sequel/database/transactions.rb:277:in `remove_transaction'
/home/travis/build/jeremyevans/sequel/lib/sequel/database/transactions.rb:157:in `_transaction'
/home/travis/build/jeremyevans/sequel/lib/sequel/database/transactions.rb:108:in `block in transaction'
/home/travis/build/jeremyevans/sequel/lib/sequel/connection_pool/threaded.rb:103:in `hold'
/home/travis/build/jeremyevans/sequel/lib/sequel/database/connecting.rb:255:in `synchronize'
/home/travis/build/jeremyevans/sequel/lib/sequel/database/transactions.rb:97:in `transaction'
/home/travis/build/jeremyevans/sequel/spec/core/database_spec.rb:1117:in `block in test_0009_should issue ROLLBACK if an exception is raised, and re-raise'
---------------

How to reproduce:

git clone git@github.com:jeremyevans/sequel.git
cd sequel
ruby -Ispec spec/core/database_spec.rb -n 'test_0009_should issue ROLLBACK if an exception is raised, and re-raise'
@headius

This comment has been minimized.

Copy link
Member

headius commented May 27, 2015

Oh nice...I think we've seen reports of this but have been unable to reproduce. This may be our opportunity. Thanks @deepj!

@headius

This comment has been minimized.

Copy link
Member

headius commented May 28, 2015

The problem lies somewhere in this method, and appears to only affect our interpreter (JIT passes the spec correctly):

    def _transaction(conn, opts=OPTS)
      rollback = opts[:rollback]
      begin
        p 1
        add_transaction(conn, opts)
        begin_transaction(conn, opts)
        if rollback == :always
          begin
            ret = yield(conn)
          rescue Exception => e1
            raise e1
          ensure
            raise ::Sequel::Rollback unless e1
          end
        else
          yield(conn)
        end
      rescue Exception => e
        p 2
        begin
          rollback_transaction(conn, opts)
        rescue Exception
        end
        transaction_error(e, :conn=>conn, :rollback=>rollback)
        ret
      ensure
        p 3
        begin
          committed = commit_or_rollback_transaction(e, conn, opts)
        rescue Exception => e2
          begin
            raise_error(e2, :classes=>database_error_classes, :conn=>conn)
          rescue Sequel::DatabaseError => e4
            begin
              rollback_transaction(conn, opts)
            ensure
              raise e4
            end
          end
        ensure
          p 4
          remove_transaction(conn, committed)
        end
      end
    end

With my stupid logging lines in there, "4" is printed twice. Something in the interpreter is running the ensure block twice. I'm trying to reduce it now. cc @enebo @subbuss

@headius

This comment has been minimized.

Copy link
Member

headius commented May 28, 2015

Still unable to reduce this to a non-Sequel example. Here's a longer version with additional output:

    def _transaction(conn, opts=OPTS)
      rollback = opts[:rollback]
      begin
        p 1
        add_transaction(conn, opts)
        begin_transaction(conn, opts)
        if rollback == :always
          begin
            p 1.1
            ret = yield(conn)
          rescue Exception => e1
            p 1.2
            raise e1
          ensure
            p 1.3
            raise ::Sequel::Rollback unless e1
          end
        else
          p 1.4
          yield(conn)
        end
      rescue Exception => e
        p 2
        begin
          p 2.1
          rollback_transaction(conn, opts)
        rescue Exception
          p 2.2
        end
        p 2.3
        transaction_error(e, :conn=>conn, :rollback=>rollback)
        ret
      ensure
        p 3
        begin
          p 3.1
          committed = commit_or_rollback_transaction(e, conn, opts)
        rescue Exception => e2
          p 3.2
          begin
            raise_error(e2, :classes=>database_error_classes, :conn=>conn)
          rescue Sequel::DatabaseError => e4
            p 3.3
            begin
              rollback_transaction(conn, opts)
            ensure
              p 3.4
              raise e4
            end
          end
        ensure
          p 4
          remove_transaction(conn, committed)
        end
      end
    end

Output:

1
1.4
2
2.1
2.3
3
3.1
4
4
@headius

This comment has been minimized.

Copy link
Member

headius commented May 28, 2015

Here's the IR for all passes for the _transaction method in question (with my p's removed): https://gist.github.com/headius/c2bff81379844624a7c2

Somewhere in the early passes this issue gets corrected. Running with -Xjit.threshold=0 works, running with -X-C -Xjit.threshold=0 also works. Only the startup interpreter fails.

@headius

This comment has been minimized.

Copy link
Member

headius commented May 28, 2015

I'm going to hand this off to @enebo because I'm not sure how to go deeper with this. Some pass is cleaning up a bad duplicate of the ensure block, but the current IR debugging output is misleading me.

@deepj

This comment has been minimized.

Copy link
Author

deepj commented May 28, 2015

@headius I'm not sure if this helps but everything seems to work on Ruby 9k pre1...

$ rake spec
/Users/deepj/.rubies/jruby-9.0.0.0.pre1/bin/jruby -e "ARGV.each{|f| require f}" ./spec/core/*_spec.rb
Run options: --seed 5085

# Running:

................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................

Finished in 7.553781s, 218.1689 runs/s, 536.0230 assertions/s.

1648 runs, 4049 assertions, 0 failures, 0 errors, 0 skips
/Users/deepj/.rubies/jruby-9.0.0.0.pre1/bin/jruby -e "ARGV.each{|f| require f}" ./spec/model/*_spec.rb
Run options: --seed 28314

# Running:

.........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................

Finished in 14.527926s, 87.6243 runs/s, 224.1201 assertions/s.

1273 runs, 3256 assertions, 0 failures, 0 errors, 0 skips
/Users/deepj/.rubies/jruby-9.0.0.0.pre1/bin/jruby -e "ARGV.each{|f| require f}" ./spec/extensions/*_spec.rb
Run options: --seed 13449

# Running:

....................................................................................................................................................................../Users/deepj/dev/oss/sequel/lib/sequel/plugins/validation_class_methods.rb:324: warning: Numerical comparison operators will no more rescue exceptions of #coerce
/Users/deepj/dev/oss/sequel/lib/sequel/plugins/validation_class_methods.rb:324: warning: in the next release. Return nil in #coerce if the coercion is impossible.
................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................/Users/deepj/dev/oss/sequel/lib/sequel/plugins/validation_helpers.rb:103: warning: Numerical comparison operators will no more rescue exceptions of #coerce
/Users/deepj/dev/oss/sequel/lib/sequel/plugins/validation_helpers.rb:103: warning: in the next release. Return nil in #coerce if the coercion is impossible.
................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................./Users/deepj/dev/oss/sequel/lib/sequel/extensions/pg_range.rb:391: warning: Numerical comparison operators will no more rescue exceptions of #coerce
/Users/deepj/dev/oss/sequel/lib/sequel/extensions/pg_range.rb:391: warning: in the next release. Return nil in #coerce if the coercion is impossible.
....................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................

Finished in 28.862770s, 78.5441 runs/s, 221.1846 assertions/s.

2267 runs, 6384 assertions, 0 failures, 0 errors, 0 skips
@subbuss

This comment has been minimized.

Copy link
Contributor

subbuss commented May 28, 2015

I suspect this is related to the $! reworking: https://github.com/jruby/jruby/commits?author=subbuss ..

@subbuss

This comment has been minimized.

Copy link
Contributor

subbuss commented May 29, 2015

I just tested with b765631 before I started working on it and it still fails. So, I think this is just something about the startup interpreter that we introduce post pre1. Will look for a bit now.

@subbuss

This comment has been minimized.

Copy link
Contributor

subbuss commented May 29, 2015

I have nailed the bug, I think. Will have to ponder a bit about the cleanest way to fix it. @headius, @enebo .. The problem is that when control exits an exception region, the rescue pc is not properly popped always. This problem goes away without the non-startup interpreter, because CFG construction takes care of this properly.

@subbuss

This comment has been minimized.

Copy link
Contributor

subbuss commented May 29, 2015

I fixed it .. but have to clean it up a bit and see if there is a better solution than adding a boolean 'exitsExcRegion' flag to jump instructions since it bloats memory slightly for the general case. Perhaps another marker instruction? Will play with it a bit.

Basically same issue that caused #2776 but a more complex scenario.

@subbuss subbuss closed this in edb6c79 May 29, 2015

@enebo enebo added this to the JRuby 9.0.0.0.rc1 milestone Jun 10, 2015

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.