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

activesupport 4.2.1 breaks timeout.rb on jruby 1.7.19 and 1.7.20 #2940

Closed
ggayan opened this issue May 14, 2015 · 8 comments
Closed

activesupport 4.2.1 breaks timeout.rb on jruby 1.7.19 and 1.7.20 #2940

ggayan opened this issue May 14, 2015 · 8 comments
Assignees
Milestone

Comments

@ggayan
Copy link

ggayan commented May 14, 2015

Hey people,

I've just reported an issue on Adhearsion when using the latest gem versions: adhearsion/adhearsion#549

What I found is that in the context of our adhearsion app, Celluloid crashes un jruby when upgrading to activesupport 4.2.1, but not on MRI. Moving back to 4.1.0 solves the problem.

I'm still trying to reduce the issue to a simple case, but this is what I've found so far:

https://gist.github.com/ggayan/5c90f10c59c4c747b6be

Any insights are greatly appreciated.

NOTE: MRI 1.9.3 as well as 2.1.5 works.

@kares
Copy link
Member

kares commented May 15, 2015

as notes by @enebo already on the gist, there's probably another runtime-exception the NPE hides
... likely related to the argument passed to timeout besides figuring out what changed in AS 4.2.x you could try a simple patch to figure out the timeout argument passed (and report back) :

require 'timeout'
Timeout.module_eval do
  class << self
    alias_method :_timeout_impl, :timeout
    def timeout(*args, &block)
      puts "Timeout.timeout(#{args.inspect})"
      _timeout_impl(*args, &block)
    end
  end
end

@ggayan
Copy link
Author

ggayan commented May 15, 2015

Thanks, I'll try that

@ggayan
Copy link
Author

ggayan commented May 22, 2015

@kares: I got Timeout.timeout([45 seconds]). It is the expected value

@kares
Copy link
Member

kares commented May 22, 2015

@ggayan or not .. seems like an AS::Duration rather than a Fixnum could you inspect the class and caller e.g. puts " ... timeout(#{args.inspect}) #{args.first.class} \n #{caller.join(" \n")}"

@ggayan
Copy link
Author

ggayan commented May 22, 2015

Gotcha!

... timeout([45 seconds]) ActiveSupport::Duration
 /Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/future-resource-1.1.0/lib/future-resource.rb:64:in `resource'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/punchblock-2.6.0/lib/punchblock/command_node.rb:29:in `response'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/adhearsion-2.6.0/lib/adhearsion/call.rb:462:in `write_and_await_response'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in `public_send'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in `dispatch'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/calls.rb:67:in `dispatch'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/future.rb:14:in `new'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/thread_handle.rb:13:in `initialize'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `call'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/celluloid-0.15.2/lib/celluloid/internal_pool.rb:100:in `create'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `call'
/Users/ggayan/.rbenv/versions/jruby-1.7.20/lib/ruby/gems/shared/gems/logging-1.8.2/lib/logging/diagnostic_context.rb:323:in `create_with_logging_context'

I'm using 45.seconds in the timeout call

@ggayan
Copy link
Author

ggayan commented May 22, 2015

I guess that I was giving a wrong argument to Timeout, which expects a Fixnum or a Float.

@ggayan ggayan closed this as completed May 22, 2015
@kares
Copy link
Member

kares commented May 23, 2015

re-opening as we still need to find the route cause for this :

jruby-1.7.20 :001 > require 'rails'
 => true 
jruby-1.7.20 :002 > require 'rails/all'
 => true 
jruby-1.7.20 :003 > ActiveSupport::VERSION::STRING
 => "4.1.10" 
jruby-1.7.20 :004 > Timeout.timeout(5.seconds) { puts 'holla!'; sleep(6) }
NameError: uninitialized constant Timeout
    from org/jruby/RubyModule.java:2733:in `const_missing'
    from (irb):4:in `evaluate'
    from org/jruby/RubyKernel.java:1111:in `eval'
    from org/jruby/RubyKernel.java:1511:in `loop'
    from org/jruby/RubyKernel.java:1274:in `catch'
    from org/jruby/RubyKernel.java:1274:in `catch'
    from /opt/local/rvm/rubies/jruby-1.7.20/bin/irb:13:in `(root)'
jruby-1.7.20 :005 > require 'timeout'
 => true 
jruby-1.7.20 :006 > Timeout.timeout(5.seconds) { puts 'holla!'; sleep(6) }
holla!
Timeout::Error: execution expired
    from org/jruby/RubyKernel.java:835:in `sleep'
    from (irb):6:in `evaluate'
    from org/jruby/ext/timeout/Timeout.java:126:in `timeout'
    from (irb):6:in `evaluate'
    from org/jruby/RubyKernel.java:1111:in `eval'
    from org/jruby/RubyKernel.java:1511:in `loop'
    from org/jruby/RubyKernel.java:1274:in `catch'
    from org/jruby/RubyKernel.java:1274:in `catch'
    from /opt/local/rvm/rubies/jruby-1.7.20/bin/irb:13:in `(root)'
jruby-1.7.20 :007 > 
jruby-1.7.20 :001 > require 'rails'
 => true 
jruby-1.7.20 :002 > require 'rails/all'
 => true 
jruby-1.7.20 :003 > ActiveSupport::VERSION::STRING
 => "4.2.1" 
jruby-1.7.20 :004 > require 'timeout'
 => true 
jruby-1.7.20 :005 > Timeout.timeout(5.seconds) { puts 'holla!'; sleep(6) }
Java::JavaLang::NullPointerException: 
    from org.jruby.ext.timeout.Timeout.killTimeoutThread(Timeout.java:219)
    from org.jruby.ext.timeout.Timeout.timeout(Timeout.java:128)
    from org.jruby.ext.timeout.Timeout$INVOKER$s$timeout.call(Timeout$INVOKER$s$timeout.gen)
    from org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:336)
    from org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:179)
    from org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:188)
    from org.jruby.ast.CallOneArgBlockNode.interpret(CallOneArgBlockNode.java:60)
    from org.jruby.ast.NewlineNode.interpret(NewlineNode.java:105)
    from org.jruby.ast.RootNode.interpret(RootNode.java:129)
    from org.jruby.evaluator.ASTInterpreter.INTERPRET_EVAL(ASTInterpreter.java:95)
    from org.jruby.evaluator.ASTInterpreter.evalWithBinding(ASTInterpreter.java:184)
    from org.jruby.RubyKernel.evalCommon(RubyKernel.java:1148)
    from org.jruby.RubyKernel.eval19(RubyKernel.java:1111)
    from org.jruby.RubyKernel$INVOKER$s$0$3$eval19.call(RubyKernel$INVOKER$s$0$3$eval19.gen)
    from org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:180)
    from org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:70)
... 115 levels...

... it's probably a 4.2 "bug" of how Duration is converted or timeout patched

@kares kares reopened this May 23, 2015
@kares kares changed the title Crash with celluloid 0.15.2 and activesupport 4.2.1 on jruby 1.7.19 and 1.7.20. MRI 2.1.5 works. activesupport 4.2.1 breaks timeout.rb on jruby 1.7.19 and 1.7.20 May 23, 2015
@kares
Copy link
Member

kares commented May 23, 2015

turns out there's difference between 4.1 and 4.2 around the type of argument passed to timeout :

4.2.1
Timeout.timeout([5 seconds]) ActiveSupport::Duration 
 timeout_bug.rb:22:in `<main>'
holla!
timeout_bug.rb:22:in `sleep': execution expired (Timeout::Error)
    from timeout_bug.rb:22:in `block in <main>'
    from timeout_bug.rb:9:in `timeout'
    from timeout_bug.rb:22:in `<main>'
kares@sputnik:~/workspace/oss/jruby$ 
kares@sputnik:~/workspace/oss/jruby$ 
kares@sputnik:~/workspace/oss/jruby$ ruby timeout_bug.rb 4.1.10
4.1.10
Timeout.timeout([5 seconds]) Fixnum 
 timeout_bug.rb:22:in `<main>'
holla!
timeout_bug.rb:22:in `sleep': execution expired (Timeout::Error)
    from timeout_bug.rb:22:in `block in <main>'
    from timeout_bug.rb:9:in `timeout'
    from timeout_bug.rb:22:in `<main>'

after 1e2d2dd the underlying issue reveals itself (on JRuby) :

4.2.1
Timeout.timeout([5 seconds]) ActiveSupport::Duration 
 timeout_bug.rb:22:in `(root)'
TypeError: can't convert ActiveSupport::Duration into Float
  timeout at org/jruby/ext/timeout/Timeout.java:122
  timeout at timeout_bug.rb:9

@kares kares self-assigned this May 24, 2015
kares added a commit to kares/jruby that referenced this issue May 24, 2015
… MRI does

... wasn't noticeable too much previously but now Rails 4.2 started using respond_to_missing? on places such as AS::Duration thus it's require for us to get things such as `sleep 5.seconds` working (fixes jruby#2940)
@kares kares closed this as completed in d246f97 May 25, 2015
kares added a commit that referenced this issue May 25, 2015
* jruby-1_7: (54 commits)
  [travis-ci] re-try sudo: false
  dry out the two (Java helper) respond_to_p19 methods
  respondsTo JRuby API under 1.9.3 does not do respond_to_missing? like MRI does
  sleep should convert it's "time interval" argument the same way as MRI
  respond_to_missing? should always get a symbol name passed (fixes #2946)
  add a respond_to_missing unit test (on 1.9)
  introduce and use conversion( just like MRI does) on #timeout's sec argument
  add missing ' ' (space) in exception message ... TypeError from `sleep('invalid')`
  DateTime.iso8601 fails with an error if a second fraction is present
  [build] switch to 1.7.21-SNAPSHOT for test-jruby-jars
  refactor Timeout's scheduled tasks to an inner class (for easier identification)
  further hand drying of the Timeout module impl
  less (int) casting noiz
  add some (internal) generics for an improved readability xp
  inner class' Finalizer fields id and finalized can be final
  generix-ize the environment field (at least internally) + use a StringBuilder
  unnecessary (int) cast
  missing throw statement in RubyString's concat
  tune timeout to work when scheduling or argument convenrsion throws (see #2940)
  return empty Ruby array for empty dir list
  ...

Conflicts:
	.gitignore
	.travis.yml
	VERSION
	core/pom.xml
	core/src/main/java/org/jruby/RubyArray.java
	core/src/main/java/org/jruby/RubyBasicObject.java
	core/src/main/java/org/jruby/RubyDir.java
	core/src/main/java/org/jruby/RubyEnumerable.java
	core/src/main/java/org/jruby/RubyFile.java
	core/src/main/java/org/jruby/RubyGlobal.java
	core/src/main/java/org/jruby/RubyIO.java
	core/src/main/java/org/jruby/RubyKernel.java
	core/src/main/java/org/jruby/RubyModule.java
	core/src/main/java/org/jruby/RubyString.java
	core/src/main/java/org/jruby/RubyTime.java
	core/src/main/java/org/jruby/ext/timeout/Timeout.java
	core/src/main/java/org/jruby/java/proxies/JavaProxy.java
	core/src/main/java/org/jruby/util/Dir.java
	core/src/main/java/org/jruby/util/encoding/CharsetTranscoder.java
	docs/man/pom.xml
	docs/pom.xml
	ext/pom.xml
	ext/readline/pom.xml
	ext/ripper/pom.xml
	lib/pom.xml
	lib/ruby/1.9/date/format.rb
	lib/ruby/1.9/io/linux_console.rb
	lib/ruby/shared/gauntlet_rubygems.rb
	lib/ruby/shared/rubygems.rb
	lib/ruby/shared/rubygems/available_set.rb
	lib/ruby/shared/rubygems/basic_specification.rb
	lib/ruby/shared/rubygems/command.rb
	lib/ruby/shared/rubygems/command_manager.rb
	lib/ruby/shared/rubygems/commands/cert_command.rb
	lib/ruby/shared/rubygems/commands/cleanup_command.rb
	lib/ruby/shared/rubygems/commands/contents_command.rb
	lib/ruby/shared/rubygems/commands/dependency_command.rb
	lib/ruby/shared/rubygems/commands/environment_command.rb
	lib/ruby/shared/rubygems/commands/generate_index_command.rb
	lib/ruby/shared/rubygems/commands/help_command.rb
	lib/ruby/shared/rubygems/commands/install_command.rb
	lib/ruby/shared/rubygems/commands/list_command.rb
	lib/ruby/shared/rubygems/commands/mirror_command.rb
	lib/ruby/shared/rubygems/commands/outdated_command.rb
	lib/ruby/shared/rubygems/commands/owner_command.rb
	lib/ruby/shared/rubygems/commands/pristine_command.rb
	lib/ruby/shared/rubygems/commands/push_command.rb
	lib/ruby/shared/rubygems/commands/query_command.rb
	lib/ruby/shared/rubygems/commands/search_command.rb
	lib/ruby/shared/rubygems/commands/setup_command.rb
	lib/ruby/shared/rubygems/commands/specification_command.rb
	lib/ruby/shared/rubygems/commands/uninstall_command.rb
	lib/ruby/shared/rubygems/commands/unpack_command.rb
	lib/ruby/shared/rubygems/commands/update_command.rb
	lib/ruby/shared/rubygems/commands/which_command.rb
	lib/ruby/shared/rubygems/commands/yank_command.rb
	lib/ruby/shared/rubygems/compatibility.rb
	lib/ruby/shared/rubygems/config_file.rb
	lib/ruby/shared/rubygems/core_ext/kernel_gem.rb
	lib/ruby/shared/rubygems/core_ext/kernel_require.rb
	lib/ruby/shared/rubygems/defaults.rb
	lib/ruby/shared/rubygems/dependency.rb
	lib/ruby/shared/rubygems/dependency_installer.rb
	lib/ruby/shared/rubygems/dependency_list.rb
	lib/ruby/shared/rubygems/deprecate.rb
	lib/ruby/shared/rubygems/doctor.rb
	lib/ruby/shared/rubygems/errors.rb
	lib/ruby/shared/rubygems/exceptions.rb
	lib/ruby/shared/rubygems/ext.rb
	lib/ruby/shared/rubygems/ext/builder.rb
	lib/ruby/shared/rubygems/ext/cmake_builder.rb
	lib/ruby/shared/rubygems/ext/configure_builder.rb
	lib/ruby/shared/rubygems/ext/ext_conf_builder.rb
	lib/ruby/shared/rubygems/ext/rake_builder.rb
	lib/ruby/shared/rubygems/gemcutter_utilities.rb
	lib/ruby/shared/rubygems/indexer.rb
	lib/ruby/shared/rubygems/install_update_options.rb
	lib/ruby/shared/rubygems/installer.rb
	lib/ruby/shared/rubygems/installer_test_case.rb
	lib/ruby/shared/rubygems/local_remote_options.rb
	lib/ruby/shared/rubygems/name_tuple.rb
	lib/ruby/shared/rubygems/package.rb
	lib/ruby/shared/rubygems/package/old.rb
	lib/ruby/shared/rubygems/package/tar_header.rb
	lib/ruby/shared/rubygems/package/tar_reader/entry.rb
	lib/ruby/shared/rubygems/package/tar_writer.rb
	lib/ruby/shared/rubygems/path_support.rb
	lib/ruby/shared/rubygems/platform.rb
	lib/ruby/shared/rubygems/psych_additions.rb
	lib/ruby/shared/rubygems/rdoc.rb
	lib/ruby/shared/rubygems/remote_fetcher.rb
	lib/ruby/shared/rubygems/request.rb
	lib/ruby/shared/rubygems/request_set.rb
	lib/ruby/shared/rubygems/request_set/gem_dependency_api.rb
	lib/ruby/shared/rubygems/requirement.rb
	lib/ruby/shared/rubygems/resolver/current_set.rb
	lib/ruby/shared/rubygems/security.rb
	lib/ruby/shared/rubygems/security/policy.rb
	lib/ruby/shared/rubygems/security/signer.rb
	lib/ruby/shared/rubygems/security/trust_dir.rb
	lib/ruby/shared/rubygems/server.rb
	lib/ruby/shared/rubygems/source.rb
	lib/ruby/shared/rubygems/source/installed.rb
	lib/ruby/shared/rubygems/source/local.rb
	lib/ruby/shared/rubygems/source/specific_file.rb
	lib/ruby/shared/rubygems/source_list.rb
	lib/ruby/shared/rubygems/spec_fetcher.rb
	lib/ruby/shared/rubygems/specification.rb
	lib/ruby/shared/rubygems/ssl_certs/AddTrustExternalCARoot.pem
	lib/ruby/shared/rubygems/stub_specification.rb
	lib/ruby/shared/rubygems/syck_hack.rb
	lib/ruby/shared/rubygems/test_case.rb
	lib/ruby/shared/rubygems/test_utilities.rb
	lib/ruby/shared/rubygems/text.rb
	lib/ruby/shared/rubygems/uninstaller.rb
	lib/ruby/shared/rubygems/uri_formatter.rb
	lib/ruby/shared/rubygems/user_interaction.rb
	lib/ruby/shared/rubygems/util/list.rb
	lib/ruby/shared/rubygems/validator.rb
	lib/ruby/shared/rubygems/version.rb
	maven/jruby-complete/pom.xml
	maven/jruby-dist/pom.xml
	maven/jruby-jars/pom.xml
	maven/jruby-noasm/pom.xml
	maven/jruby-rake-plugin/pom.xml
	maven/jruby-stdlib/pom.xml
	maven/jruby/pom.xml
	maven/pom.xml
	pom.xml
	test/pom.xml
	test/test_dir.rb
	test/test_kernel.rb
	test/test_respond_to.rb
	test/test_timeout.rb
@kares kares added this to the JRuby 1.7.21 milestone May 25, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants