Bug 1402235

DESCRIPTION OF PROBLEM:

  Using cryptography.fernet.Fernet in RHEL 7.3.1 via mod_wsgi doesn't work the first few times after httpd is started. When it fails, it errors out in /usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py with:

  > InternalError: Unknown OpenSSL error. This error is commonly encountered when another library is not cleaning up the OpenSSL error stack. If you are using cryptography with another library that uses OpenSSL try disabling it before reporting a bug. Otherwise please file an issue at https://github.com/pyca/cryptography/issues with information on how to reproduce this. ([_OpenSSLErrorWithText(code=151441516L, lib=9, func=109, reason=108, reason_text='error:0906D06C:PEM routines:PEM_read_bio:no start line'), _OpenSSLErrorWithText(code=151441516L, lib=9, func=109, reason=108, reason_text='error:0906D06C:PEM routines:PEM_read_bio:no start line')])

  After 5 or so failures, it starts working and then seems to not fail any more until the next httpd restart.

VERSION-RELEASE NUMBER OF SELECTED COMPONENT (IF APPLICABLE):

  python2-cryptography-1.3.1-3.el7.x86_64
  httpd-2.4.6-45.el7.x86_64
  openssl-1.0.1e-60.el7.x86_64
  (Also updated all packages to RHEL 7.3.1, Dec 7)

HOW REPRODUCIBLE:

  100%, right after starting/restarting httpd

STEPS TO REPRODUCE:

  1. yum install -y python-cffi mod_wsgi httpd python2-cryptography
  
  2. yum update
  
  3. reboot
  
  4. echo WSGIScriptAlias /test_fernet /var/www/cryptotest.wsgi >/etc/httpd/conf.d/test_fernet.conf 
  
  5. cat >/var/www/cryptotest.wsgi <<\EOF
def test_fernet(input='sample input text'):
    import logging
    logging.basicConfig(format="test_fernet: %(message)s", level='DEBUG')
    logging.debug(">>> from cryptography.fernet import Fernet")
    from cryptography.fernet import Fernet
    logging.debug(">>> Fernet.generate_key()")
    key = Fernet.generate_key()
    logging.info("KEY:   '{}'".format(key))
    f = Fernet(key)
    logging.info("INPUT: '{}'".format(input))
    e = f.encrypt(bytes(input))
    logging.info("ENC:   '{}'".format(e))
    d = f.decrypt(bytes(e))
    logging.info("DEC:   '{}'".format(d))
    return "COMPLETED\n"

def application(environ, start_response):
    output = test_fernet()
    response_headers = [('Content-type', 'text/plain'), ('Content-Length', str(len(output)))]
    start_response('200 OK', response_headers)
    return [output]

if __name__ == '__main__':
    print(test_fernet())
EOF

  6. systemctl restart httpd
  
  7. for i in {1..30}; do curl -s --head localhost/test_fernet | head -1; done


ACTUAL RESULTS:

  [root@r73 ~]# for i in {1..30}; do curl -s --head localhost/test_fernet | head -1; done
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 500 Internal Server Error
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK

  From httpd's error_log:
    
  test_fernet: >>> from cryptography.fernet import Fernet
  test_fernet: >>> Fernet.generate_key()
  test_fernet: KEY:   'D_0AykLrKC5wTwcJ6gBRJQqU_rvB9VSU1XWF-RFBHpk='
  [client ::1:44590] mod_wsgi (pid=23141): Exception occurred processing WSGI script '/var/www/cryptotest.wsgi'.
  [client ::1:44590] Traceback (most recent call last):
  [client ::1:44590]   File "/var/www/cryptotest.wsgi", line 18, in application
  [client ::1:44590]     output = test_fernet()
  [client ::1:44590]   File "/var/www/cryptotest.wsgi", line 9, in test_fernet
  [client ::1:44590]     f = Fernet(key)
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/fernet.py", line 32, in __init__
  [client ::1:44590]     backend = default_backend()
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/backends/__init__.py", line 40, in default_backend
  [client ::1:44590]     _default_backend = MultiBackend(_available_backends())
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/backends/__init__.py", line 27, in _available_backends
  [client ::1:44590]     "cryptography.backends"
  [client ::1:44590]   File "/usr/lib/python2.7/site-packages/pkg_resources.py", line 2260, in load
  [client ::1:44590]     entry = __import__(self.module_name, globals(),globals(), ['__name__'])
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/backends/openssl/__init__.py", line 7, in <module>
  [client ::1:44590]     from cryptography.hazmat.backends.openssl.backend import backend
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/backends/openssl/backend.py", line 46, in <module>
  [client ::1:44590]     from cryptography.hazmat.bindings.openssl import binding
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py", line 225, in <module>
  [client ::1:44590]     Binding.init_static_locks()
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py", line 181, in init_static_locks
  [client ::1:44590]     cls._ensure_ffi_initialized()
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py", line 176, in _ensure_ffi_initialized
  [client ::1:44590]     cls._register_osrandom_engine()
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py", line 141, in _register_osrandom_engine
  [client ::1:44590]     _openssl_assert(cls.lib, cls.lib.ERR_peek_error() == 0)
  [client ::1:44590]   File "/usr/lib64/python2.7/site-packages/cryptography/hazmat/bindings/openssl/binding.py", line 63, in _openssl_assert
  [client ::1:44590]     errors_with_text
  [client ::1:44590] InternalError: Unknown OpenSSL error. This error is commonly encountered when another library is not cleaning up the OpenSSL error stack. If you are using cryptography with another library that uses OpenSSL try disabling it before reporting a bug. Otherwise please file an issue at https://github.com/pyca/cryptography/issues with information on how to reproduce this. ([_OpenSSLErrorWithText(code=151441516L, lib=9, func=109, reason=108, reason_text='error:0906D06C:PEM routines:PEM_read_bio:no start line'), _OpenSSLErrorWithText(code=151441516L, lib=9, func=109, reason=108, reason_text='error:0906D06C:PEM routines:PEM_read_bio:no start line')])

EXPECTED RESULTS:

  Should work immediately, i.e., thirty 200 OK status returns.
  
ADDITIONAL INFO:

  Note that the same test in Fedora25 meets success all-around.

  [root@f25 ~]# rpm -q python2-cryptography openssl httpd
  python2-cryptography-1.5.3-3.fc25.x86_64
  openssl-1.0.2j-1.fc25.x86_64
  httpd-2.4.23-4.fc25.x86_64
  [root@f25 ~]# systemctl restart httpd; for i in {1..10}; do curl -s --head localhost/test_fernet | head -1; done 
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  HTTP/1.1 200 OK
  [root@f25 ~]# tail -6 /var/log/httpd/error_log | grep -o ".pid.*"
  [pid 8546] test_fernet: >>> from cryptography.fernet import Fernet
  [pid 8546] test_fernet: >>> Fernet.generate_key()
  [pid 8546] test_fernet: KEY:   'Li8hOE73GFt8sGbtSCHSJ7tr7v6MCDc9DC7CFXNmJfc='
  [pid 8546] test_fernet: INPUT: 'sample input text'
  [pid 8546] test_fernet: ENC:   'gAAAAABYR6bq3Rn1Dp1Tv2xLNeXnT8kWgyEtYbWc-R-HZjS-S57fHx3T0xDbubX_QW__-v1ya7GRkIylxTo5efFNpojJ_25EXEq8RKOrq8Ait42USPq2R-4='
  [pid 8546] test_fernet: DEC:   'sample input text'