celluloid / reel

UNMAINTAINED: See celluloid/celluloid#779 - Celluloid::IO-powered web server
https://celluloid.io
MIT License
596 stars 87 forks source link

Reel::Server::HTTPS crashes on "Errno::ECONNRESET: Connection reset by peer - SSL_accept" #153

Closed mig1984 closed 9 years ago

mig1984 commented 10 years ago

Hello,

when I send lots of requests, a reel https server experiences ECONNRESET (even with increased backlog). The bad thing is, it crashes on further issues and restarts.

The program:

require 'reel'

class Webserver < Reel::Server::HTTPS

   def initialize()
      options = {:cert=>File.read('server.crt'),
                 :key=>File.read('server.key')}
      super('127.0.0.1', 1111, options, &method(:on_connection))
   end

   def on_connection(connection)
      while request = connection.request
         request.respond :ok, 'foobar'
      end
   end

end

Webserver.supervise_as :reel

sleep
ab -v 1 -k -c 150 -n 1000 https://127.0.0.1:1111/
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
SSL handshake failed (5).
SSL handshake failed (5).
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests

Server Software:
Server Hostname:        127.0.0.1
Server Port:            1111
SSL/TLS Protocol:       TLSv1.2,DHE-RSA-AES256-GCM-SHA384,1024,256

Document Path:          /
Document Length:        6 bytes

Concurrency Level:      150
Time taken for tests:   8.896 seconds
Complete requests:      1000
Failed requests:        2
   (Connect: 0, Receive: 0, Length: 2, Exceptions: 0)
Write errors:           0
Keep-Alive requests:    0
Total transferred:      63102 bytes
HTML transferred:       5988 bytes
Requests per second:    112.41 [#/sec] (mean)
Time per request:       1334.387 [ms] (mean)
Time per request:       8.896 [ms] (mean, across all concurrent requests)
Transfer rate:          6.93 [Kbytes/sec] received
E, [2014-06-19T13:44:11.435580 #18542] ERROR -- : Webserver crashed!
Errno::ECONNRESET: Connection reset by peer - SSL_accept
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-io-0.15.0/lib/celluloid/io/ssl_socket.rb:26:in 'accept_nonblock'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-io-0.15.0/lib/celluloid/io/ssl_socket.rb:26:in 'accept'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-io-0.15.0/lib/celluloid/io/ssl_server.rb:26:in 'accept'
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/server/https.rb:52:in 'block in run'
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/server/https.rb:50:in 'loop'
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/server/https.rb:50:in 'run'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in 'public_send'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in 'dispatch'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:122:in 'dispatch'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/actor.rb:322:in 'block in handle_message'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/actor.rb:416:in 'block in task'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/tasks.rb:55:in 'block in initialize'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:13:in 'block in create'
W, [2014-06-19T13:44:11.436462 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:11.437076 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:11.437354 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:11.437619 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:11.437933 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:11.438190 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:20.797228 #18542]  WARN -- : Error accepting SSLSocket: OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A
W, [2014-06-19T13:44:20.800541 #18542]  WARN -- : Error accepting SSLSocket: OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A
W, [2014-06-19T13:44:20.802708 #18542]  WARN -- : Error accepting SSLSocket: OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A
W, [2014-06-19T13:44:20.804832 #18542]  WARN -- : Error accepting SSLSocket: OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A
W, [2014-06-19T13:44:39.536508 #18542]  WARN -- : Error accepting SSLSocket: OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=SSLv3 read client certificate A
E, [2014-06-19T13:44:39.537254 #18542] ERROR -- : Webserver crashed!
Reel::StateError: already processing a request
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/connection.rb:55:in 'request'
        r.rb:12:in 'on_connection'
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/server.rb:56:in 'call'
        /usr/local/lib64/ruby/gems/1.9.1/gems/reel-0.5.0/lib/reel/server.rb:56:in 'handle_connection'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in 'public_send'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:25:in 'dispatch'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/calls.rb:122:in 'dispatch'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/actor.rb:322:in 'block in handle_message'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/actor.rb:416:in 'block in task'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/tasks.rb:55:in 'block in initialize'
        /usr/local/lib64/ruby/gems/1.9.1/gems/celluloid-0.15.2/lib/celluloid/tasks/task_fiber.rb:13:in 'block in create'
W, [2014-06-19T13:44:39.537809 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:run}, status=:iowait
W, [2014-06-19T13:44:39.537937 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:39.538066 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:39.538398 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:39.538875 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:39.539079 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
W, [2014-06-19T13:44:39.539401 #18542]  WARN -- : Terminating task: type=:call, meta={:method_name=>:handle_connection}, status=:iowait
my environment:

ruby 1.9.3p484 (2013-11-22 revision 43786) [x86_64-linux]

gems:

celluloid-0.15.2
celluloid-io-0.15.0
http-0.6.1
http_parser.rb-0.6.0
nio4r-1.0.0
reel-0.5.0
timers-1.1.0
websocket_parser-0.1.6
tarcieri commented 10 years ago

We likely need to add ECONNRESET to the exceptions Reel::Server::HTTPS rescues. This also speaks to the more general need for a (Celluloid) server framework.

digitalextremist commented 9 years ago

This is pretty old, but I was able to replicate the issue with a slightly different error now.

See failure: https://gist.github.com/digitalextremist/bfa56ed40900fd23d65c

Out of curiosity, I changed the request handler to this:

      connection.each_request do |request|
         request.respond :ok, 'foobar'
      end

Same error.

Then I noticed #136 and changed from Rubinius to jRuby, and I started getting this:

https://gist.github.com/digitalextremist/c40dba6c814dbaea3c8b

digitalextremist commented 9 years ago

Released in 0.6.0.pre1