Engine: atexit crash when used with softhsm2

[aalba6675]

There is a crash when engine is used with softhsm2, specifically with EC key operation.

Fedora 28 Downstream: https://bugzilla.redhat.com/show_bug.cgi?id=1619184
SoftHSM2: softhsm/SoftHSMv2#413

1. Crash happens only with EC keys
2. Crash happens when another HSM does EC key operations but softhsm2 is loaded and configured. I have configured CloudHSM+SoftHSM2.

Distro suggests it is a conflict between engine's finish and softhsm2's atexit. Not sure who is a "fault" here but maintainers may be interested in taking a look. Downstream has two suggestions:

1. Build softhsm2 with -fno-use-cxa-atexit
2. Use LD_PRELOAD=/usr/local/lib/softhsm/libsofthsm2.so

I can confirm that both workarounds avoid the crash. Cross-posting the issue here looking for the best place to apply C++-fu.

[aalba6675]

For reference the crash looks like

Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `openssl req -config openssl.cnf -new -subj /CN=testing -engine pkcs11 -keyform'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	  return ret;
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007faa883dd5c1 in __GI_abort () at abort.c:79
#2  0x00007faa884359d7 in __libc_message (action=action@entry=do_abort, 
    fmt=fmt@entry=0x7faa8853f639 "%s\n") at ../sysdeps/posix/libc_fatal.c:181
#3  0x00007faa8843beac in malloc_printerr (str=str@entry=0x7faa8853d77d "corrupted size vs. prev_size")
    at malloc.c:5350
#4  0x00007faa8843c104 in malloc_consolidate (av=av@entry=0x7faa88775c40 <main_arena>) at malloc.c:4456
#5  0x00007faa8843ed70 in _int_malloc (av=av@entry=0x7faa88775c40 <main_arena>, bytes=bytes@entry=4096)
    at malloc.c:3703
#6  0x00007faa88440653 in __GI___libc_malloc (bytes=bytes@entry=4096) at malloc.c:3057
#7  0x00007faa873a971c in operator new (sz=sz@entry=4096)
    at ../../../../libstdc++-v3/libsupc++/new_op.cc:50
#8  0x00007faa87a09e47 in __gnu_cxx::new_allocator<char>::allocate (this=<optimized out>, __n=4096)
    at /usr/include/c++/8/bits/vector.tcc:580
#9  std::allocator_traits<std::allocator<char> >::allocate (__a=..., __n=4096)
    at /usr/include/c++/8/bits/alloc_traits.h:436
#10 std::_Vector_base<char, std::allocator<char> >::_M_allocate (this=<optimized out>, __n=<optimized out>)
    at /usr/include/c++/8/bits/stl_vector.h:296
#11 std::vector<char, std::allocator<char> >::_M_default_append (this=this@entry=0x7ffe2ef02bb0, 
    __n=__n@entry=4096) at /usr/include/c++/8/bits/vector.tcc:604
#12 0x00007faa87a09840 in std::vector<char, std::allocator<char> >::resize (__new_size=4096, 
    this=0x7ffe2ef02bb0) at log.cpp:95
#13 softHSMLog(int, char const*, char const*, int, char const*, ...) () at log.cpp:95
#14 0x00007faa87a0a45e in OSLockMutex (mutex=0x562a463220f0) at osmutex.cpp:111
#15 0x00007faa87a0b26b in MutexFactory::LockMutex (mutex=<optimized out>, this=<optimized out>)
    at MutexFactory.cpp:183
#16 Mutex::lock (this=0x562a462faaa0) at MutexFactory.cpp:61
#17 0x00007faa87a380a1 in SessionObjectStore::sessionClosed(unsigned long) () at SessionObjectStore.cpp:146
#18 0x00007faa879e585d in SoftHSM::C_CloseSession (this=0x562a46321450, hSession=1) at SoftHSM.cpp:1237
#19 0x00007faa879cbeb8 in C_CloseSession () at main.cpp:332
#20 0x00007faa87eb1531 in managed_C_CloseSession (self=<optimized out>, session=1)
    at p11-kit/modules.c:1741
#21 0x00007faa87ecad24 in binding_C_CloseSession (cif=<optimized out>, ret=0x7ffe2ef03150, 
    args=<optimized out>, funcs=<optimized out>) at p11-kit/virtual.c:292
#22 0x00007faa87c71e35 in ffi_closure_unix64_inner (closure=<optimized out>, rvalue=<optimized out>, 
    reg_args=<optimized out>, argp=0x7ffe2ef03170 "\b") at ../src/x86/ffi64.c:670
#23 0x00007faa87c721a6 in ffi_closure_unix64 () at ../src/x86/unix64.S:229
#24 0x00007faa87ea14f4 in proxy_C_CloseSession (self=self@entry=0x562a462e74e0, handle=<optimized out>)
    at p11-kit/proxy.c:629
#25 0x00007faa87ea1680 in proxy_C_CloseAllSessions (self=0x562a462e74e0, id=<optimized out>)
    at p11-kit/proxy.c:679
#26 0x00007faa87ecad44 in binding_C_CloseAllSessions (cif=<optimized out>, ret=0x7ffe2ef033d0, 
    args=<optimized out>, funcs=<optimized out>) at p11-kit/virtual.c:302
#27 0x00007faa87c71e35 in ffi_closure_unix64_inner (closure=<optimized out>, rvalue=<optimized out>, 
    reg_args=<optimized out>, argp=0x7ffe2ef033f0 "") at ../src/x86/ffi64.c:670
#28 0x00007faa87c721a6 in ffi_closure_unix64 () at ../src/x86/unix64.S:229
#29 0x00007faa881b4fac in pkcs11_release_slot (ctx=ctx@entry=0x562a462ddaa0, 
    slot=slot@entry=0x562a463220a0) at p11_slot.c:459
---Type <return> to continue, or q <return> to quit--- 
#30 0x00007faa881b53df in pkcs11_release_all_slots (ctx=0x562a462ddaa0, slots=0x562a463220a0, 
    nslots=<optimized out>) at p11_slot.c:446
#31 0x00007faa881b580c in PKCS11_release_all_slots (ctx=<optimized out>, slots=<optimized out>, 
    nslots=<optimized out>) at p11_front.c:228
#32 0x00007faa881ae332 in ctx_finish (ctx=0x562a462dd2a0) at eng_back.c:353
#33 0x00007faa881ac4dc in engine_finish (engine=<optimized out>) at eng_front.c:206
#34 0x00007faa88eeb17b in engine_unlocked_finish () from /lib64/libcrypto.so.1.1
#35 0x00007faa88eed016 in int_cleanup_cb_doall () from /lib64/libcrypto.so.1.1
#36 0x00007faa88f15c09 in OPENSSL_LH_doall () from /lib64/libcrypto.so.1.1
#37 0x00007faa88eed341 in engine_table_cleanup () from /lib64/libcrypto.so.1.1
#38 0x00007faa88eeb3aa in engine_cleanup_cb_free () from /lib64/libcrypto.so.1.1
#39 0x00007faa88f6cc60 in OPENSSL_sk_pop_free () from /lib64/libcrypto.so.1.1
#40 0x00007faa88eeb6e0 in engine_cleanup_int () from /lib64/libcrypto.so.1.1
#41 0x00007faa88f13cfe in OPENSSL_cleanup () from /lib64/libcrypto.so.1.1
#42 0x00007faa883f572c in __run_exit_handlers (status=0, listp=0x7faa88775718 <__exit_funcs>, 
    run_list_atexit=run_list_atexit@entry=true, run_dtors=run_dtors@entry=true) at exit.c:108
#43 0x00007faa883f585c in __GI_exit (status=<optimized out>) at exit.c:139
#44 0x0000562a4409ae06 in main (argc=<optimized out>, argv=<optimized out>) at apps/openssl.c:266

[mtrojnar]

Thank you. Please try running the command with valgrind. It should be able to automatically find the source of the heap corruption that caused this crash.

[aalba6675]

valgrind.log

All the errors look to descend from OpenSSL calling exit() - then lots of Invalid read/write/free

p11-kit-0.23.12-1.fc28.x86_64
softhsm-2.3.0-4.fc28.x86_64

[mtrojnar]

Interesting. Do I see correctly that valgrind prevented the code from crashing?

[aalba6675]

Yes! It did not segfault under valgrind.

[mtrojnar]

It looks to me like there are several double free issues in libsofthsm2.so, for example:

==21451== Invalid free() / delete / delete[] / realloc()
==21451==    at 0x4C3029C: operator delete(void*) (vg_replace_malloc.c:576)
==21451==    by 0x6AB7743: ??? (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x6A9EBE7: C_Finalize (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x657D026: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x657D1D8: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6596AF3: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6879E34: ffi_closure_unix64_inner (in /usr/lib64/libffi.so.6.0.2)
==21451==    by 0x687A1A5: ffi_closure_unix64 (in /usr/lib64/libffi.so.6.0.2)
==21451==    by 0x657F520: p11_kit_modules_finalize (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x656C73C: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x656C824: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6596AF3: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==  Address 0x6095880 is 0 bytes inside a block of size 120 free'd
==21451==    at 0x4C3029C: operator delete(void*) (vg_replace_malloc.c:576)
==21451==    by 0x6AB6C90: ??? (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x6AB6CEC: ??? (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x5BA772B: __run_exit_handlers (in /usr/lib64/libc-2.27.so)
==21451==    by 0x5BA785B: exit (in /usr/lib64/libc-2.27.so)
==21451==    by 0x135E05: main (openssl.c:266)
==21451==  Block was alloc'd at
==21451==    at 0x4C2F226: operator new(unsigned long) (vg_replace_malloc.c:334)
==21451==    by 0x6AB748F: ??? (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x6A9EBB7: C_Initialize (in /usr/lib64/pkcs11/libsofthsm2.so)
==21451==    by 0x657C634: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x657C7F2: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6596AD3: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6879E34: ffi_closure_unix64_inner (in /usr/lib64/libffi.so.6.0.2)
==21451==    by 0x687A1A5: ffi_closure_unix64 (in /usr/lib64/libffi.so.6.0.2)
==21451==    by 0x657F3AF: p11_kit_modules_initialize (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x656C99B: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6596AD3: ??? (in /usr/lib64/libp11-kit.so.0.3.0)
==21451==    by 0x6879E34: ffi_closure_unix64_inner (in /usr/lib64/libffi.so.6.0.2)

[aalba6675]

Looks like a bug in engine not softhsm2, analyzed by @ansasaki #243

[aalba6675]

Fixed by 0a2df89 , see #243