Segfault on python3.5.1, cryptography 1.2.1 but not on 1.1.2 [MAC-EL CAPITAN]

[dhilton]

This code here: https://github.com/ONSdigital/eq-survey-runner/blob/jwt/jwt_tester.py

Runs fine under 1.1.2 but segfaults under 1.2.1 (valgrind details):

Token file XXXXXX

==69239== Invalid read of size 4
==69239==    at 0x10074D066: _PyObject_Free (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AC49B: PyEval_EvalFrameEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AF6DF: _PyEval_EvalCodeWithName (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007A6AC6: PyEval_EvalCodeEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100731B9F: function_call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100722787: method_call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10075A968: slot_tp_init (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100757CED: type_call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007ABFB6: PyEval_EvalFrameEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==  Address 0x103845020 is 1,744 bytes inside a block of size 1,777 free'd
==69239==    at 0x10000A920: realloc (in /opt/boxen/homebrew/Cellar/valgrind/3.11.0/lib/valgrind/vgpreload_memcheck-amd64-darwin.so)
==69239==    by 0x100719BD1: _PyBytes_Resize (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10080DDA9: _io_FileIO_readall_impl (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007106DD: PyObject_CallMethodObjArgs (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100811088: _io__Buffered_read (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AC25A: PyEval_EvalFrameEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AF6DF: _PyEval_EvalCodeWithName (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007A6AC6: PyEval_EvalCodeEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100731B9F: function_call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==  Block was alloc'd at
==69239==    at 0x100009EBB: malloc (in /opt/boxen/homebrew/Cellar/valgrind/3.11.0/lib/valgrind/vgpreload_memcheck-amd64-darwin.so)
==69239==    by 0x10074D633: _PyObject_Alloc (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071928E: _PyBytes_FromSize (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007191C9: PyBytes_FromStringAndSize (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10080DCBE: _io_FileIO_readall_impl (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007106DD: PyObject_CallMethodObjArgs (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x100811088: _io__Buffered_read (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AC25A: PyEval_EvalFrameEx (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007AF6DF: _PyEval_EvalCodeWithName (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==
Encoded tag XXXX
Decrypted Token: XXXXX

line 164
Decoded token: {'user': 'jimmy'}

==69239== Warning: set address range perms: large range [0x2393dc040, 0xa711441e0) (undefined)




==69239== Invalid read of size 4
==69239==    at 0x106F63119: general_invoke_callback (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x106F64366: cffi_call_python (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x1076C4A24: Cryptography_locking_cb (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x107586776: CRYPTO_add_lock (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x10762FB6F: EVP_PKEY_free (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x1076DDC56: _cffi_f_EVP_PKEY_free (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10070D0E3: PyObject_CallFunctionObjArgs (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x106F64B05: gcp_finalize (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x1007E0B03: collect (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007E0434: _PyGC_CollectNoFail (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==  Address 0x50 is not stack'd, malloc'd or (recently) free'd
==69239==
==69239==
==69239== Process terminating with default action of signal 11 (SIGSEGV)
==69239==  Access not within mapped region at address 0x50
==69239==    at 0x106F63119: general_invoke_callback (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x106F64366: cffi_call_python (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x1076C4A24: Cryptography_locking_cb (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x107586776: CRYPTO_add_lock (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x10762FB6F: EVP_PKEY_free (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x1076DDC56: _cffi_f_EVP_PKEY_free (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/cryptography/hazmat/bindings/_openssl.cpython-35m-darwin.so)
==69239==    by 0x1007489C4: PyCFunction_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10071004D: PyObject_Call (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x10070D0E3: PyObject_CallFunctionObjArgs (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x106F64B05: gcp_finalize (in /Users/danhilton/.virtualenvs/eq-survey-runner/lib/python3.5/site-packages/_cffi_backend.cpython-35m-darwin.so)
==69239==    by 0x1007E0B03: collect (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==    by 0x1007E0434: _PyGC_CollectNoFail (in /opt/boxen/homebrew/Cellar/python3/3.5.1/Frameworks/Python.framework/Versions/3.5/Python)
==69239==  If you believe this happened as a result of a stack
==69239==  overflow in your program's main thread (unlikely but
==69239==  possible), you can try to increase the size of the
==69239==  main thread stack using the --main-stacksize= flag.
==69239==  The main thread stack size used in this run was 16777216.
==69239==
==69239== HEAP SUMMARY:
==69239==     in use at exit: 35,314,669,086 bytes in 16,212 blocks
==69239==   total heap usage: 64,790 allocs, 48,578 frees, 35,476,247,282 bytes allocated
==69239==
^C
^D
exit
quit
^C
pause break
^[[21~^[[21~==69239== LEAK SUMMARY:
==69239==    definitely lost: 146,641 bytes in 113 blocks
==69239==    indirectly lost: 167,492 bytes in 5,364 blocks
==69239==      possibly lost: 91,670 bytes in 205 blocks
==69239==    still reachable: 35,314,204,190 bytes in 10,359 blocks
==69239==         suppressed: 59,093 bytes in 171 blocks
==69239== Rerun with --leak-check=full to see details of leaked memory
==69239==
==69239== For counts of detected and suppressed errors, rerun with: -v
==69239== Use --track-origins=yes to see where uninitialised values come from
==69239== ERROR SUMMARY: 1617 errors from 113 contexts (suppressed: 0 from 0)
[1]    69239 segmentation fault  valgrind python jwt_tester.py

We've run this on multiple different machines, and clean virtualenv environments. We're porting this code from python2.7 to python3.5, where we had no issues on python2.7.

Any ideas as to why this is happening? Anything else I can add to this bug report to help?

Cheers for the help!

[collisdigital]

I've stripped the code back to the simplest case that causes the problem, it appears to be related to holding a private key as a class member variable (see attached txt Python script). If in the example I've attached you make rrm_privatekey a local variable instead of member (i.e. remove self.) then no seg fault occurs. Something to do with the way classes clean-up members on exit?

Note also that calling "del self.rrm_privatekey" in the example immediately after creating it also prevents the seg fault. I tried adding a del to the Encoder class that does the same, but that didn't solve it...

jwt_tester.txt

[collisdigital]

Even simpler example, seg faults:

from cryptography.hazmat.backends import default_backend
from cryptography.hazmat.primitives.asymmetric import rsa

class Encoder(object):
    def __init__(self):
        self.private_key = rsa.generate_private_key(
            public_exponent=65537,
            key_size=2048,
            backend=default_backend())

encoder = Encoder()

[reaperhulk]

Interesting, thanks for the reduced test case @collisdigital that's extremely helpful. It's suggestive that the crash is occurring when trying to free the EVP_PKEY inside the Cryptography_locking_cb. In 1.2 we moved to a new static callback pointer model, but if I revert to the old style callbacks then the crash goes away. cc @tiran

[collisdigital]

@reaperhulk anything we can do to work around this issue or just roll back to 1.1 and wait for a fix?

[reaperhulk]

If you need something from 1.2 then the workaround is to modify setup.py to lower the cffi version requirement and then install cffi 1.3.1 before installing cryptography. This will cause it to fallback to the old style callback model (which we still support for older pypy compatibility). If you don't need anything in 1.2 right now I'd recommend just using the older version while we work on the fix :)

[collisdigital]

👍

[reaperhulk]

This crash goes away when the build is not statically linked (which the wheels are). This might turn into a fun linker adventure.

[kmike]

Not sure if it helps, but I'm getting a related error when shutting down a Twisted-based HTTP downloader (Scrapy): there is a lot of these messages at shutdown, and process doesn't seem to exit cleanly

extern "Python": function Cryptography_locking_cb() called, but got internal exception (out of memory?). Returning 0.

OS X, Python 3.5.1, cryptography 1.2.1, cffi 1.5.0. Downgrading to cryptography 1.1 seems to help.

[reaperhulk]

Yeah that's likely the same bug (and it's also probable #2658 is related)

[tiran]

I'm unable to reproduce the issue on Linux. During my work on static callbacks I tested the lock_cb with locks set by _ssl module and with Cryptography's own locking. Both were working fine. I did another series of tests today. When I comment out __import__('_ssl') I can see a lot of calls to _lock_cb(). The code is working and tests are passing without segfaults on my system.

[reaperhulk]

I've filed this as an issue with cffi (https://bitbucket.org/cffi/cffi/issues/246/crash-during-interpreter-shutdown-when). More theorizing is available there.

[alex]

This should be fixed by a patch just landed on cffi's default branch. Can you try installing that and confirm this if this is fixed?

[alex]

(Also closing as a duplicate of #2658)