+++ This bug was initially created as a clone of Bug #1831086 +++

My OpenConnect builds are failing on rawhide. It turns out that when softhsm is used, it prevents the process from exiting cleanly.

Reproduce by just rebuilding the openconnect RPM. Or checkout out from git://git.infradead.org/users/dwmw2/openconnect.git and running 'make check'...


make  check-TESTS
make[2]: Entering directory '/home/dwmw2/git/openconnect/gtls/tests'
make[3]: Entering directory '/home/dwmw2/git/openconnect/gtls/tests'
PASS: autocompletion
PASS: auth-username-pass
PASS: auth-certificate
PASS: auth-nonascii
PASS: cert-fingerprint
PASS: id-test


The test it's stuck on, and hasn't printed yet, is auth-pkcs11. If I connect to the stuck openconnect process with gdb, I see this backtrace:

919	      if ((atomic_load_acquire (&rwlock->__data.__readers)
(gdb) bt
#0  0x00007f3be4ed14b7 in __pthread_rwlock_wrlock_full (abstime=0x0, rwlock=0x134f7b0) at pthread_rwlock_common.c:919
#1  __GI___pthread_rwlock_wrlock (rwlock=0x134f7b0) at pthread_rwlock_wrlock.c:27
#2  0x00007f3be4bfbe7d in CRYPTO_THREAD_write_lock (lock=<optimized out>) at crypto/threads_pthread.c:78
#3  0x00007f3be4b61745 in ENGINE_finish (e=0x134f7f0) at crypto/engine/eng_init.c:101
#4  0x00007f3bd4b55e8b in OSSLCryptoFactory::~OSSLCryptoFactory() () from /usr/lib64/pkcs11/libsofthsm2.so
#5  0x00007f3bd4b55f1d in OSSLCryptoFactory::~OSSLCryptoFactory() () from /usr/lib64/pkcs11/libsofthsm2.so
#6  0x00007f3be4d38680 in __run_exit_handlers (status=status@entry=0, listp=0x7f3be4ebe738 <__exit_funcs>, run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108
#7  0x00007f3be4d387c0 in __GI_exit (status=status@entry=0) at exit.c:139
#8  0x0000000000403f4c in main (argc=<optimized out>, argv=<optimized out>) at ../main.c:1906

--- Additional comment from David Woodhouse on 2020-05-04 19:22:36 EEST ---

==228434== Invalid read of size 4
==228434==    at 0x54D9316: __pthread_rwlock_wrlock_full (pthread_rwlock_common.c:581)
==228434==    by 0x54D9316: pthread_rwlock_wrlock (pthread_rwlock_wrlock.c:27)
==228434==    by 0x58ADE7C: CRYPTO_THREAD_write_lock (threads_pthread.c:78)
==228434==    by 0x5813744: ENGINE_finish (eng_init.c:101)
==228434==    by 0x134794D6: OSSLCryptoFactory::~OSSLCryptoFactory() (OSSLCryptoFactory.cpp:240)
==228434==    by 0x13479558: OSSLCryptoFactory::~OSSLCryptoFactory() (OSSLCryptoFactory.cpp:259)
==228434==    by 0x552767F: __run_exit_handlers (exit.c:108)
==228434==    by 0x55277BF: exit (exit.c:139)
==228434==    by 0x404043: main (main.c:1553)
==228434==  Address 0x14bb74c8 is 24 bytes inside a block of size 56 free'd
==228434==    at 0x4839A0C: free (vg_replace_malloc.c:540)
==228434==    by 0x583FBE1: OPENSSL_cleanup (init.c:601)
==228434==    by 0x583FBE1: OPENSSL_cleanup (init.c:497)
==228434==    by 0x552767F: __run_exit_handlers (exit.c:108)
==228434==    by 0x55277BF: exit (exit.c:139)
==228434==    by 0x404043: main (main.c:1553)
==228434==  Block was alloc'd at
==228434==    at 0x483880B: malloc (vg_replace_malloc.c:309)
==228434==    by 0x584859D: CRYPTO_zalloc (mem.c:230)
==228434==    by 0x58ADE0B: CRYPTO_THREAD_lock_new (threads_pthread.c:29)
==228434==    by 0x58137B9: do_engine_lock_init (eng_lib.c:25)
==228434==    by 0x58137B9: do_engine_lock_init_ossl_ (eng_lib.c:21)
==228434==    by 0x54DBD7E: __pthread_once_slow (pthread_once.c:116)
==228434==    by 0x58ADEFC: CRYPTO_THREAD_run_once (threads_pthread.c:118)
==228434==    by 0x5813878: ENGINE_new (eng_lib.c:33)
==228434==    by 0x58152FD: ENGINE_rdrand (eng_rdrand.c:70)
==228434==    by 0x58152FD: engine_load_rdrand_int (eng_rdrand.c:85)
==228434==    by 0x583F8BC: ossl_init_engine_rdrand (init.c:353)
==228434==    by 0x583F8BC: ossl_init_engine_rdrand_ossl_ (init.c:347)
==228434==    by 0x54DBD7E: __pthread_once_slow (pthread_once.c:116)
==228434==    by 0x58ADEFC: CRYPTO_THREAD_run_once (threads_pthread.c:118)
==228434==    by 0x584004C: OPENSSL_init_crypto (init.c:723)
==228434==    by 0x584004C: OPENSSL_init_crypto (init.c:620)

--- Additional comment from David Woodhouse on 2020-05-07 17:22:32 EEST ---

This is because SoftHSM's atexit hander (well, the destructor for the OSSLCryptoFactory object) is trying to clean up the rdrand engine after OpenSSL's own atexit handler has run and cleaned up *everything*.

Proof of concept fix at https://github.com/dwmw2/SoftHSMv2/commit/f9c24e04f21e241ee93dd862f5ebb56dd54461c5

I've worked around it for now in my OpenConnect builds by exporting OPENSSL_ia32cap=~0x4000000000000000 when running the tests, to disable RDRAND.

--- Additional comment from David Woodhouse on 2020-05-12 17:06:02 EEST ---

Fix merged: https://github.com/opendnssec/SoftHSMv2/commit/c2cc0652b4c4829fc6ba186469f4e324af77dfe8

--- Additional comment from Fedora Update System on 2020-05-12 18:50:01 EEST ---

FEDORA-2020-3735365352 has been submitted as an update to Fedora 32. https://bodhi.fedoraproject.org/updates/FEDORA-2020-3735365352