ruby / webrick

HTTP server toolkit
BSD 2-Clause "Simplified" License
286 stars 97 forks source link

Handle OpenSSL::SSL:SSLError #71

Open ekohl opened 3 years ago

ekohl commented 3 years ago

We use a server config where Webrick also handles HTTPS. When a connection is aborted, an exception is logged. For example:

$ nc localhost 8443
$ cat server.log
2021-05-26T11:52:34  [E] <OpenSSL::SSL::SSLError> SSL_accept SYSCALL returned=5 errno=0 state=before SSL initialization
        /usr/share/ruby/webrick/server.rb:299:in `accept'
        /usr/share/ruby/webrick/server.rb:299:in `block (2 levels) in start_thread'
        /usr/share/ruby/webrick/utils.rb:263:in `timeout'
        /usr/share/ruby/webrick/server.rb:297:in `block in start_thread'
        /usr/share/gems/gems/logging-2.3.0/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'

This comes from: https://github.com/ruby/webrick/blob/3515081a51b91b730267ba2b224039ecfbf8bd7b/lib/webrick/server.rb#L252-L277

It does look like various basic network errors are caught and ignored, but SSL errors can fall in the same category (such as this one). Not everything should be logged at the error level. I'm not sure how it should exactly be dealt with (or I'd submit a patch instead of a PR) so I'm looking for input on this.

gotoken commented 3 years ago

In HTTPS server sinario, server.rb has two different rescues depend on execption types during OpenSSL::SSL::SSLSocket#accept:

The possible options for your suggestion may be:

Option 1 seems hard to accept because WEBrick does not provide error-specific handling convention at the socket layer. In my opinion, it's common to send unintended incorrect packets or requests to a server under development. Because I want webrick to report these errors as logs, I like the current behavior, option 3.

By the way, as the code you refered looks slightly old version, I reproduced the situation with webrick-1.7.0, current latest version of gem, as follows.

% openssl req -new -newkey rsa:2048 -sha1 -days 365 -nodes -x509 -keyout localhost.key -out localhost.crt
% ruby  -r webrick/https -e 's = WEBrick::HTTPServer.new(Port: 8443, SSLEnable: true, SSLVerifyClient: OpenSSL::SSL::VERIFY_NONE, SSLPrivateKey: OpenSSL::PKey::RSA.new(File.open("localhost.key").read), SSLCertificate: OpenSSL::X509::Certificate.new(File.open("localhost.crt").read), SSLCertName: [["CN", "localhost"]]); trap("INT"){s.shutdown}; s.start'

and open with nc command and kill by Ctrl+c from another terminal

% nc localhost 8443
^C

then I got the same error on the first terminal

[2021-08-23 00:27:34] ERROR OpenSSL::SSL::SSLError: SSL_accept SYSCALL returned=5 errno=0 state=before SSL initialization
        /home/gotoken/.rbenv/versions/3.0.2/lib/ruby/gems/3.0.0/gems/webrick-1.7.0/lib/webrick/server.rb:302:in `accept'
        /home/gotoken/.rbenv/versions/3.0.2/lib/ruby/gems/3.0.0/gems/webrick-1.7.0/lib/webrick/server.rb:302:in `block (2 levels) in start_thread'
        /home/gotoken/.rbenv/versions/3.0.2/lib/ruby/gems/3.0.0/gems/webrick-1.7.0/lib/webrick/utils.rb:258:in `timeout'
        /home/gotoken/.rbenv/versions/3.0.2/lib/ruby/gems/3.0.0/gems/webrick-1.7.0/lib/webrick/server.rb:300:in `block in start_thread'

The error raised at line 302 and rescued at 316 of https://github.com/ruby/webrick/blob/v1.7.0/lib/webrick/server.rb#L288-L329

ekohl commented 3 years ago

But does it need to be at the error level? Looking at https://en.wikipedia.org/wiki/Syslog#Severity_level I wonder if it we can't downgrade it to a lower level. My problem is mostly that this service is used in production and these are conditions that fill the logs. However, there's little an admin can do about this. Ignoring errors in logs is a bad practice, but right now there's little other choice.

gotoken commented 3 years ago

However, there's little an admin can do about this

Indeed. What do you think of debug level log?

--- a/lib/webrick/server.rb
+++ b/lib/webrick/server.rb
@@ -313,6 +313,8 @@ module WEBrick
         rescue ServerError => ex
           msg = "#{ex.class}: #{ex.message}\n\t#{ex.backtrace[0]}"
           @logger.error msg
+        rescue OpenSSL::SSL::SSLError => ex
+          @logger.debug ex
         rescue Exception => ex
           @logger.error ex
         ensure

It is not immediately clear to me whether OpenSSL::SSL is legal here. OpenSSL might not be defined in non ssl cases.

ekohl commented 3 years ago

Yes, that would solve my problem. And I suspect you could be right that OpenSSL may not be available. At least, I've seen code in Puma that explicitly tries to deal with a Ruby that wasn't linked against OpenSSL. Perhaps it should be something like:

rescue Exception => ex
  if defined?(OpenSSL::SSL::SSLError) && ex.is_a?(OpenSSL::SSL::SSLError)
    @logger.debug(ex)
  else
    @logger.error(ex)
end

Disclaimer: this is the first code I write on a Monday morning so don't expect it to literally work but I'm sure you get the idea.