Ticket #589 (defect)

Fixed in [1410].

I'm getting these errors again in trunk.

This is intermittent, by the way, but occurs while trying to send an error message. The initial error is:

Traceback (most recent call last):
  File "C:\Python24\Lib\site-packages\cherrypy\wsgiserver\__init__.py", line 751, in communicate
    req.parse_request()
  File "C:\Python24\Lib\site-packages\cherrypy\wsgiserver\__init__.py", line 246, in parse_request
    self._parse_request()
  File "C:\Python24\Lib\site-packages\cherrypy\wsgiserver\__init__.py", line 259, in _parse_request
    request_line = self.rfile.readline()
  File "C:\Python24\Lib\site-packages\cherrypy\wsgiserver\__init__.py", line 154, in readline
    data = self.rfile.readline(256)
  File "C:\Python24\Lib\site-packages\cherrypy\wsgiserver\__init__.py", line 645, in ssl_method_wrapper
    return method(self, *args, **kwargs)
  File "C:\Python24\lib\socket.py", line 359, in readline
    data = self._sock.recv(self._rbufsize)
Error: [('SSL routines', 'SSL3_GET_RECORD', 'decryption failed or bad record mac')]

This might be due to a bad openssl version. See http://svn.haxx.se/users/archive-2006-03/0803.shtml.

Also getting several of these in test_refleaks:

C:\Python24\Lib\site-packages>python cherrypy\test\test.py --ssl --test_refleaks
Python version used to run this test script: 2.4.4
CherryPy version 3.1.0beta3
HTTP server version HTTP/1.1 (ssl)
PID: 5544


Running tests: cherrypy._cpwsgi.CPWSGIServer
test_threadlocal_garbage (test_refleaks.ReferenceTests) ... Exception in thread Thread-18:
Traceback (most recent call last):
  File "C:\Python24\lib\threading.py", line 442, in __bootstrap
    self.run()
  File "C:\Python24\lib\threading.py", line 422, in run
    self.__target(*self.__args, **self.__kwargs)
  File "C:\Python24\Lib\site-packages\cherrypy\test\test_refleaks.py", line 94, in getpage
    c.request('GET', '/')
  File "C:\Python24\lib\httplib.py", line 804, in request
    self._send_request(method, url, body, headers)
  File "C:\Python24\lib\httplib.py", line 827, in _send_request
    self.endheaders()
  File "C:\Python24\lib\httplib.py", line 798, in endheaders
    self._send_output()
  File "C:\Python24\lib\httplib.py", line 679, in _send_output
    self.send(msg)
  File "C:\Python24\lib\httplib.py", line 646, in send
    self.connect()
  File "C:\Python24\lib\httplib.py", line 1073, in connect
    ssl = socket.ssl(sock, self.key_file, self.cert_file)
  File "C:\Python24\lib\socket.py", line 74, in ssl
    return _realssl(sock, keyfile, certfile)
sslerror: (8, 'EOF occurred in violation of protocol')

These occur after the server receives the error: [('SSL routines', 'SSL23_READ', 'ssl handshake failure')] during the first socket readline call.

ssldump of one good conn, one bad_record_mac

The attached sslcompare.log is a partial ssldump of test_refleaks when it fails. Connection #23 succeeds, #24 fails with a "bad_record_mac" alert.

Command used:

ssldump -dAaHtn -i lo -k cherrypy/test/test.pem port 8080 > ssl.log

...then, in another terminal, run:

python cherrypy/test/test.py --ssl --test_refleaks

It looks like the alert is raised in response to a Handshake: Finished message from client to server. According to Rescorla, "...if the alert is sent in response to a Finished message, it could also represent an error in key derivation. Even if the encryption keys are also wrong, the decryption may appear to succeed. However, the MAC will fail. In fact, even if the MAC key is correct but the encryption key is wrong, the error will still most likely appear in the MAC check..."

Oh, and the "unknown" cipher suite 0x35 is:

CipherSuite TLS_RSA_WITH_AES_256_CBC_SHA      = { 0x00, 0x35 };

according to http://www.ietf.org/rfc/rfc3268.txt. But using Context.set_cipher_list() to remove it didn't help the test pass.

I'm starting to think this isn't an SSL bug per se; I'm getting similar errors when running test_refleaks without ssl. They appear when printing debug info or otherwise loading the process, and go away when, for example, I use skip_host with httplib to avoid the idna encoding overhead. So there's definitely a timing issue somewhere. When using --ssl, the first 10 requests are received by all 10 worker threads, but then they all lock up in WantRead loops until they timeout. Without ssl, some client threads immediately receive "Connection reset by peer" messages instead.

Wanted to confirm this issue ... just started after moving to 3.1 ... here's my traceback:

[05/Jul/2008:14:09:54] ENGINE Serving on 0.0.0.0:8080
[05/Jul/2008:14:09:54] ENGINE Bus STARTED
Exception in thread CP WSGIServer Thread-4:
Traceback (most recent call last):
  File "/usr/lib/python2.5/threading.py", line 486, in __bootstrap_inner
    self.run()
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 1073, in run
    conn.communicate()
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 1015, in communicate
    req.simple_response("500 Internal Server Error", format_exc())
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 591, in simple_response
    self.wfile.sendall("".join(buf))
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 920, in sendall
    return self._safe_call(False, super(SSL_fileobject, self).sendall, *args, **kwargs)
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 872, in _safe_call
    return call(*args, **kwargs)
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 721, in sendall
    bytes_sent = self.send(data)
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 923, in send
    return self._safe_call(False, super(SSL_fileobject, self).send, *args, **kwargs)
  File "/home/user/test/cherrypy/wsgiserver/__init__.py", line 902, in _safe_call
    raise FatalSSLAlert(*e.args)
FatalSSLAlert: [('SSL routines', 'SSL23_WRITE', 'ssl handshake failure')]