jruby-openssl icon indicating copy to clipboard operation
jruby-openssl copied to clipboard

OpenSSL::X509::Store#set_default_paths is much slower in v. 0.9.17 than v. 0.9.5

Open thomas07vt opened this issue 8 years ago • 5 comments

This has been ported over from https://github.com/jruby/jruby/issues/4238

##bench.rb

require 'jruby/profiler'
require 'openssl'

ENV['SSL_CERT_FILE'] = '/etc/pki/tls/certs/ca-bundle.crt'

puts `ruby -v`
puts `java -version`
puts `gem list | grep jruby-openssl`
puts `stat /etc/pki/tls/certs/ca-bundle.crt | grep -E '(File|Size)'`

profile_data = JRuby::Profiler.profile do
  10.times { OpenSSL::X509::Store.new.set_default_paths }
end
profile_printer = JRuby::Profiler::FlatProfilePrinter.new(profile_data)
profile_printer.printProfile(STDOUT)


##Results

$ jruby --profile.api bench.rb 
Profiling enabled; ^C shutdown will now dump profile info
jruby 1.7.19 (1.9.3p551) 2015-01-29 20786bd on Java HotSpot(TM) 64-Bit Server VM 1.8.0_111-b14 +jit [linux-amd64]

jruby-openssl (0.9.5 java)
  File: ‘/etc/pki/tls/certs/ca-bundle.crt’
  Size: 263596    	Blocks: 520        IO Block: 4096   regular file
Total time: 0.79

     total        self    children       calls  method
----------------------------------------------------------------
      0.79        0.00        0.79           1  Fixnum#times
      0.79        0.79        0.00          10  OpenSSL::X509::Store#set_default_paths
      0.00        0.00        0.00          10  Class#new
      0.00        0.00        0.00          10  OpenSSL::X509::Store#initialize
$ jruby --profile.api bench.rb 
Profiling enabled; ^C shutdown will now dump profile info
jruby 1.7.19 (1.9.3p551) 2015-01-29 20786bd on Java HotSpot(TM) 64-Bit Server VM 1.8.0_111-b14 +jit [linux-amd64]

jruby-openssl (0.9.17 java, 0.9.5 java)
  File: ‘/etc/pki/tls/certs/ca-bundle.crt’
  Size: 263596    	Blocks: 520        IO Block: 4096   regular file
Total time: 3.07

     total        self    children       calls  method
----------------------------------------------------------------
      3.07        0.00        3.07           1  Fixnum#times
      3.06        3.06        0.00          10  OpenSSL::X509::Store#set_default_paths
      0.00        0.00        0.00          10  Class#new
      0.00        0.00        0.00          10  OpenSSL::X509::Store#initialize

And for the sake of completeness... same issue in jruby 9.1.5.0

$ jruby --profile.api bench.rb
Profiling enabled; ^C shutdown will now dump profile info
jruby 9.1.5.0 (2.3.1) 2016-09-07 036ce39 Java HotSpot(TM) 64-Bit Server VM 25.111-b14 on 1.8.0_111-b14 +jit [linux-x86_64]
java version "1.8.0_111"
Java(TM) SE Runtime Environment (build 1.8.0_111-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.111-b14, mixed mode)

jruby-openssl (0.9.17 java)
  File: ‘/etc/pki/tls/certs/ca-bundle.crt’
  Size: 263596    	Blocks: 520        IO Block: 4096   regular file
Total time: 3.17

     total        self    children       calls  method
----------------------------------------------------------------
      3.17        0.00        3.17           1  Fixnum#times
      3.17        3.17        0.00          10  OpenSSL::X509::Store#set_default_paths
      0.00        0.00        0.00          10  Class#new
      0.00        0.00        0.00          10  OpenSSL::X509::Store#initialize

Want to see this issue resolved? Post a bounty on it! We accept bounties via Bountysource.

--- Want to back this issue? **[Post a bounty on it!](https://www.bountysource.com/issues/38896190-openssl-x509-store-set_default_paths-is-much-slower-in-v-0-9-17-than-v-0-9-5?utm_campaign=plugin&utm_content=tracker%2F136995&utm_medium=issues&utm_source=github)** We accept bounties via [Bountysource](https://www.bountysource.com/?utm_campaign=plugin&utm_content=tracker%2F136995&utm_medium=issues&utm_source=github).

thomas07vt avatar Nov 02 '16 18:11 thomas07vt

able to confirm the issue using the Ubuntu standard: /etc/ssl/certs/ca-certificates.crt (about the same size: 274340). the slowness seems to be coming from all the X.509 certificate comparison, there's some potential caching going on but that with comes more memory consumption -J-Djruby.openssl.x509.lookup.cache=true ... it still needs to clone X.509 certificate objects so its only about ~20% improvement for me locally.

currently, there's no obvious fix for this, it might need some work looking into the details (such as lightweight BC certificates) and figuring out a smart way to do the lookup/matching.

kares avatar Nov 07 '16 07:11 kares

I was about to submit this very same issue. We're seeing this having a showstopping impact - 10's of seconds per invocation in a highly concurrent environment.

JasonLunn avatar Nov 08 '16 19:11 JasonLunn

@JasonLunn use the Java cacert file instead... It's much faster to parse

thomas07vt avatar Nov 08 '16 19:11 thomas07vt

On the AMI of Amazon Linux we use, /etc/pki/tls/certs/ca-bundle.crt is 877042. @thomas07vt - we're not expressly picking a CACert file now - what's your setup to use the one from Java as you're describing?

JasonLunn avatar Nov 08 '16 20:11 JasonLunn

We set this at startup:

ENV['SSL_CERT_FILE']='/usr/java/latest/jre/lib/security/cacerts'

Its much faster. You can checkout the benchmarks I reported in this issue: https://github.com/jruby/jruby/issues/4238

Look at the bench2.rb file and results

EDIT: @JasonLunn

thomas07vt avatar Nov 08 '16 20:11 thomas07vt