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

Performance issues using oauth gem #4654

Closed
BrunoChauvet opened this issue Jun 8, 2017 · 3 comments
Closed

Performance issues using oauth gem #4654

BrunoChauvet opened this issue Jun 8, 2017 · 3 comments

Comments

@BrunoChauvet
Copy link

Environment

  • JRuby version: observed on version 9.1.7.0, 9.1.8.0, 9.1.10.0
  • Operating system and platform: Linux Ubuntu-14.04 4.4.0-75-generic

Context

Using the gem oauth to access APIs, JRuby is showing a massive slowdown in a multi-threaded environment.
To highlight the problem, the following snippet of code can be executed. It should send 10 concurrent requests using oauth to an endpoint responding after 2 seconds delay.

require 'oauth'

puts "Start test (oauth version #{Gem.loaded_specs["oauth"].version})"
puts "JRUBY_VERSION: #{JRUBY_VERSION}" if defined?(JRUBY_VERSION)
puts "RUBY_VERSION: #{RUBY_VERSION}" if defined?(RUBY_VERSION)
puts "RUBY_ENGINE: #{RUBY_ENGINE}" if defined?(RUBY_ENGINE)

start = Time.now.to_f
threads = []

10.times do |i|
  threads << Thread.new do
    start = Time.now.to_f

    consumer = OAuth::Consumer.new('username', 'password', {})
    token = OAuth::AccessToken.new(consumer, 'token', 'secret')
    token.get('http://www.fakeresponse.com/api/?sleep=2&api_key=your_token') # this is where it gets stuck

    finish = Time.now.to_f
    puts "done thread #{i} in #{finish - start}ms\n"
  end
end

threads.each { |t| t.join }
finish = Time.now.to_f
puts "Done in #{finish - start}ms"

Running with MRI

Start test (oauth version 0.5.3)
RUBY_VERSION: 2.3.3
RUBY_ENGINE: ruby
done thread 2 in 2.446808099746704ms
done thread 0 in 2.454033613204956ms
done thread 1 in 2.4543349742889404ms
done thread 3 in 2.4549062252044678ms
done thread 4 in 2.455209732055664ms
done thread 8 in 2.4559578895568848ms
done thread 5 in 4.480912685394287ms
done thread 9 in 4.488664627075195ms
done thread 6 in 4.490235805511475ms
done thread 7 in 4.4907145500183105ms
Done in 4.490761756896973ms

Using jruby-9.1.7.0

Start test (oauth version 0.5.3)
JRUBY_VERSION: 9.1.7.0
RUBY_VERSION: 2.3.1
RUBY_ENGINE: jruby
done thread 2 in 67.8659999370575ms
done thread 0 in 90.4079999923706ms
done thread 8 in 114.18999981880188ms
done thread 9 in 136.64800000190735ms
done thread 4 in 154.90499997138977ms
done thread 7 in 184.22299981117249ms
done thread 5 in 201.4029998779297ms
done thread 1 in 220.03099989891052ms
done thread 3 in 243.8529999256134ms
done thread 6 in 267.62399983406067ms
Done in 267.62399983406067ms

Using jruby-9.1.10.0

Start test (oauth version 0.5.3)
JRUBY_VERSION: 9.1.10.0
RUBY_VERSION: 2.3.3
RUBY_ENGINE: jruby
done thread 6 in 65.79614400863647ms
done thread 8 in 85.54032707214355ms
done thread 1 in 113.79753613471985ms
done thread 5 in 133.92187595367432ms
done thread 7 in 161.2085702419281ms
done thread 4 in 279.4656300544739ms
done thread 0 in 298.20193219184875ms
done thread 9 in 319.00907707214355ms
done thread 3 in 354.0950779914856ms
done thread 2 in 380.21208000183105ms
Done in 380.2126340866089ms

I'm more than happy to run this using a profiler if it can help with finding the root cause of the issue.

@kares
Copy link
Member

kares commented Jun 8, 2017

running the profiler with the report might have been useful.
anyway, to be sure this isn't another entropy depleting issue could you please re-run with :
export JRUBY_OPTS=-J-Djava.security.egd=file:/dev/./urandom

@BrunoChauvet
Copy link
Author

It looks like it fixes the issue 👍

Start test (oauth version 0.5.3)
JRUBY_VERSION: 9.1.10.0
RUBY_VERSION: 2.3.3
RUBY_ENGINE: jruby
done thread 0 in 2.6283040046691895ms
done thread 1 in 2.632622241973877ms
done thread 9 in 2.632991313934326ms
done thread 4 in 2.632991313934326ms
done thread 8 in 2.628237009048462ms
done thread 5 in 2.6283931732177734ms
done thread 2 in 4.63171911239624ms
done thread 6 in 4.6337502002716064ms
done thread 3 in 4.6337502002716064ms
done thread 7 in 4.6343560218811035ms
Done in 4.634951114654541ms

Thanks for the quick answer

@kares kares added this to the Invalid or Duplicate milestone Jun 8, 2017
@kares
Copy link
Member

kares commented Jun 8, 2017

closing as a duplicate ... we hopefully do smt about it at jruby/jruby-openssl#135
... still entropy depletion is a common issue with JVM and there's no easy piece JRuby can do about it.

@kares kares closed this as completed Jun 8, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants