Reactor changes in 1.6 seems to break SSL servers

[bporterfield]

Hello!

Trying to upgrade to Puma 1.6, but the changes appear to break SSL servers.

To test - config.ru:

class Test
  def call(env)
    puts 'call'
    return [200, {}, ["hello"]]
  end
end
run Test.new

Starting with: puma -b tcp://127.0.0.1:3000 config.ru and hitting http://localhost:3000 returns outputs call and returns hello to the browser.

Starting with

puma -b 'ssl://127.0.0.1:3000?key=puma/puma_keypair.pem&cert=puma/cert_puma.pem' config.ru

and hitting https://localhost:3000 just spins. If I cancel the request from the browser, call is then output.

Same results in 1.6 and master. Using JRuby 1.6.7, testing with Chrome and Firefox on Max OS X.

[evanphx]

1.6 is under testing, thats why there is no gem for it yet :D

A bunch of fixes went in yesterday, when did you try it?

[bporterfield]

Ah! Didn't realize it hadn't been released yet. Bad assumption on my part :D

I pulled a few hours ago to test, so I reckon I've tried with the most recent.

[evanphx]

I just tested against git master and I don't seem to see what you're seeing. I tried the setup you said and it seemed to work fine. Could you give me more details of what you're seeing? Do you see any console output?

[bporterfield]

Sure. I've cloned the repo from master into ~/puma and built puma_http11.jar using rake compile. I can't just use bundler and gem 'puma', :git => path_to_repo b/c of #42 (which I think is a bundler issue and not yours).

Gemfile:

source :rubygems
gem 'jruby-openssl'
gem 'puma', :path => "~/puma"

I'm using the keys from examples/puma. Using the config.ru I provided above, the working case (http://localhost:3000) looks like:

bporterfield@ ~/dev/pumatest$bundle exec puma -b tcp://127.0.0.1:3000 config.ru
Puma 1.6.0 starting...
* Min threads: 0, max threads: 16
* Environment: development
* Listening on tcp://127.0.0.1:3000
Use Ctrl-C to stop
call
127.0.0.1 - - [25/Jul/2012 18:37:03] "GET / HTTP/1.1" 200 - 0.0030
call
127.0.0.1 - - [25/Jul/2012 18:37:03] "GET /favicon.ico HTTP/1.1" 200 - 0.0010

and the failure case(https://localhost:3000) looks like:

bporterfield@ ~/dev/pumatest$ bundle exec puma -b 'ssl://127.0.0.1:3000?key=puma/puma_keypair.pem&cert=puma/cert_puma.pem' config.ru
Puma 1.6.0 starting...
* Min threads: 0, max threads: 16
* Environment: development
* Listening on ssl://127.0.0.1:3000?key=puma/puma_keypair.pem&cert=puma/cert_puma.pem
Use Ctrl-C to stop
call

In the failure case, Chrome just spins until I hit the stop button, after which call is output.

ruby -v:jruby 1.6.7 (ruby-1.9.2-p312) (2012-02-22 3e82bc8) (Java HotSpot(TM) 64-Bit Server VM 1.7.0_04) [darwin-x86_64-java]

Chrome version: Version 20.0.1132.57

In Firefox the results look slightly different:

bporterfield@ ~/dev/pumatest$ bundle exec puma -b 'ssl://127.0.0.1:3000?key=puma/puma_keypair.pem&cert=puma/cert_puma.pem' config.ru
Puma 1.6.0 starting...
* Min threads: 0, max threads: 16
* Environment: development
* Listening on ssl://127.0.0.1:3000?key=puma/puma_keypair.pem&cert=puma/cert_puma.pem
Use Ctrl-C to stop
call
127.0.0.1 - - [25/Jul/2012 19:01:05] "GET / HTTP/1.1" 200 - 0.0030
2012-07-25 19:01:05 -0700: Read error: #<IOError: Broken pipe>
org/jruby/ext/openssl/SSLSocket.java:602:in `syswrite'
/Users/bporterfield/.rvm/gems/jruby-1.6.7@global/gems/jruby-openssl-0.7.6.1/lib/1.9/openssl/buffering.rb:317:in `do_write'
/Users/bporterfield/.rvm/gems/jruby-1.6.7@global/gems/jruby-openssl-0.7.6.1/lib/1.9/openssl/buffering.rb:335:in `write'
/Users/bporterfield/dev/puma/lib/puma/server.rb:512:in `handle_request'
/Users/bporterfield/dev/puma/lib/puma/server.rb:301:in `process_client'
/Users/bporterfield/dev/puma/lib/puma/server.rb:214:in `run'
org/jruby/RubyProc.java:258:in `call'
/Users/bporterfield/dev/puma/lib/puma/thread_pool.rb:94:in `spawn_thread'

Same story here, Firefox spins until I hit stop, after which there is output from puma to the console (starting with call). Firefox v10.0.2.

In Safari, the request works immediately. Safari Version 5.1.7 (7534.57.2).

Let me know if there's anything else I can provide!

[evanphx]

This has been fixed by working around a buffering behavior in JRuby's OpenSSL.

[bporterfield]

So far from my testing the problem seems to remain - at least on Chrome and Firefox. I've pulled the latest this AM and am running master branch. Anything additional info can provide?

[evanphx]

That's very surprising. I need to know exactly what your config.ru is so that I can reproduce what you're seeing exactly.

[bporterfield]

Sure - maybe I'm just hitting some strange bundler/rvm issue or something. At any rate, my config.ru:

class Test
  def call(env)
    puts 'call'
    return [200, {}, ["hello"]]
  end
end
run Test.new

Gemfile:

source :rubygems

gem 'rack'
gem 'jruby-openssl'
gem 'puma', :path => "~/dev/puma2", :branch => 'master'

starting the server and hitting it with chrome:

bundle exec bin/puma -b 'ssl://127.0.0.1:3000?key=puma_keypair.pem&cert=cert_puma.pem' config.ru
Puma 1.6.0 starting...
* Min threads: 0, max threads: 16
* Environment: development
* Listening on ssl://127.0.0.1:3000?key=puma_keypair.pem&cert=cert_puma.pem
Use Ctrl-C to stop

Chrome is now spinning, and once I hit stop on chrome, "call" is output.

jruby version:

ruby -v
jruby 1.6.7 (ruby-1.9.2-p312) (2012-02-22 3e82bc8) (Java HotSpot(TM) 64-Bit Server VM 1.7.0_04) [darwin-x86_64-java]

[bporterfield]

Anything else I can provide here to help?

[evanphx]

So, I'm getting back around to this. I just pushed a jruby-ssl-bug branch that shows that it seems that OpenSSL in JRuby has a fatal bug. IO.select says there is data but doing a sysread_nonblock always raises IO::WaitReadable, thus going into a loop. @headius could you weigh in here? It seems like a bug I can't work around.

[bporterfield]

Thanks for looking into this again! I'll take a look tonight and see if one of the way's I've monkey-patched OpenSSL for my project will make this work for me in it's current state

[evanphx]

I've started an experiment today of not using the stock OpenSSL and instead writing MiniSSL that has just enough of what I need and none of the bugs. Hopefully I'll have it done this week.

• Evan // via iPhone

On Aug 22, 2012, at 5:27 PM, Ben Porterfield notifications@github.com wrote:

Thanks for looking into this again! I'll take a look tonight and see if one of the way's I've monkey-patched OpenSSL for my project will make this work for me in it's current state

—
Reply to this email directly or view it on GitHub.

[bporterfield]

I've attempted to create a simple gist of this bug: https://gist.github.com/3531448

Works in 1.9.3, raises 'read would raise' in JRuby 1.7-pre2.

Can you confirm that this accurately represents the problem before I submit to JRuby issues? This stuff is pretty new to me so another opinion is helpful.

[evanphx]

The problem appears to be bugs in how JRuby's jruby-ossl gem in 1.6 handles nonblocking. I guess there is a bunch of fixes in 1.7 though, so you could try that instead.

I'm going to have to implement the MiniSSL engine (which is coming along) to work around these bugs to work on JRuby 1.6 I believe.

[bporterfield]

I actually was testing in 1.7-pre2 - looks like it still exists there. I'll submit the bug. Thanks for the work on MiniSSL stuff, that will be great!

On that note - today in Puma, SSL handshake happens in the accept call to an SSLServer - this suggests to me that handshakes block the listen loop, so lots of SSL handshakes could slow down the server. Would moving the handshake to the worker thread increase performance?

[evanphx]

Yes, the handshake is happening inside the listen loop, and yes we should move it into the initial worker thread. Doing that with the current OpenSSL API is more difficult because parts of that are hidden, but doing it with MiniSSL should be trivial.

[evanphx]

Turns out that there are just too many bugs in JRuby's OpenSSL right now. I've disabled SSL support on JRuby for now as a result. We'll reevaluate in the future.

[steveklabnik]

This shit was crazy complicated. :/

[headius]

This could probably be reevaluated. I will try to get to it myself some day, but if someone else wants to poke at it we'd appreciate it.

Either the new ossl stuff @evanphx wrote or the now-bundled-and-fixed-and-working ossl library in JRuby 1.7+ should be able to support this.

[bporterfield]

Thanks @headius for taking a look! You're correct, the reported bug (https://gist.github.com/bporterfield/3531448) is no longer broken in JRuby 1.7+.

However, @evanphx wrote the reactor changes in a way that is still broken in JRuby because of a different JRuby ossl bug: https://gist.github.com/bporterfield/3557313.

I've got a ticket filed for this bug: https://jira.codehaus.org/browse/JRUBY-6874. Would love some attention to it - we're using a much much older version of Puma as a consequence.

[mindscratch]

@bporterfield - I've added my vote to that JIRA issue, as I'm also in the same boat as you.