Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memory leak when PKCS11 is enabled in openssl.cnf #358

Open
vgottardi2 opened this issue Sep 28, 2020 · 13 comments
Open

Memory leak when PKCS11 is enabled in openssl.cnf #358

vgottardi2 opened this issue Sep 28, 2020 · 13 comments

Comments

@vgottardi2
Copy link

Valgrind reports memory leaks when the PKCS11 engine is enabled in OpenSSL config. No particular module needs to be in use.
We noticed the leaks in our application using libcurl, however it's easy to reproduce with curl in Ubuntu.

[openssl_init]
engines=engine_section

[engine_section]
pkcs11 = pkcs11_section

[pkcs11_section]
engine_id = pkcs11
init = 0
$ valgrind --tool=memcheck --leak-check=full curl https://google.com
==22820== Memcheck, a memory error detector
==22820== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==22820== Using Valgrind-3.13.0 and LibVEX; rerun with -h for copyright info
==22820== Command: curl https://google.com
==22820== 
<HTML><HEAD><meta http-equiv="content-type" content="text/html;charset=utf-8">
<TITLE>301 Moved</TITLE></HEAD><BODY>
<H1>301 Moved</H1>
The document has moved
<A HREF="https://www.google.com/">here</A>.
</BODY></HTML>
==22820== 
==22820== HEAP SUMMARY:
==22820==     in use at exit: 2,050 bytes in 10 blocks
==22820==   total heap usage: 32,614 allocs, 32,604 frees, 3,115,560 bytes allocated
==22820== 
==22820== 120 bytes in 1 blocks are definitely lost in loss record 3 of 7
==22820==    at 0x4C2FB0F: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==22820==    by 0x6966E58: CRYPTO_zalloc (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68F6DC9: EC_KEY_METHOD_new (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0xB8FDB02: ???
==22820==    by 0xB8F6B36: ???
==22820==    by 0x693F9CB: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x693F1A9: ENGINE_ctrl_cmd_string (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x694122D: ENGINE_by_id (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x693E8B4: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68CEDD1: CONF_modules_load (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68CF37D: CONF_modules_load_file (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x50A15BD: ??? (in /usr/lib/x86_64-linux-gnu/libcurl.so.4.5.0)
==22820== 
==22820== 138 (120 direct, 18 indirect) bytes in 1 blocks are definitely lost in loss record 4 of 7
==22820==    at 0x4C2FB0F: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==22820==    by 0x6995DDE: RSA_meth_dup (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0xB8FCF41: ???
==22820==    by 0xB8F6B1E: ???
==22820==    by 0x693F9CB: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x693F1A9: ENGINE_ctrl_cmd_string (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x694122D: ENGINE_by_id (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x693E8B4: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68CEDD1: CONF_modules_load (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68CF37D: CONF_modules_load_file (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x50A15BD: ??? (in /usr/lib/x86_64-linux-gnu/libcurl.so.4.5.0)
==22820==    by 0x506EE3B: ??? (in /usr/lib/x86_64-linux-gnu/libcurl.so.4.5.0)
==22820== 
==22820== 1,760 (208 direct, 1,552 indirect) bytes in 2 blocks are definitely lost in loss record 7 of 7
==22820==    at 0x4C2FB0F: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==22820==    by 0x68AB506: BN_MONT_CTX_new (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68AB96C: BN_MONT_CTX_set_locked (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x6997D64: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x699BBDF: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x699BF69: RSA_verify (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x699A5E1: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x695BB14: EVP_DigestVerifyFinal (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x68803AD: ASN1_item_verify (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x69DEA13: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x69E0675: ??? (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820==    by 0x69E0E95: X509_verify_cert (in /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1)
==22820== 
==22820== LEAK SUMMARY:
==22820==    definitely lost: 448 bytes in 4 blocks
==22820==    indirectly lost: 1,570 bytes in 5 blocks
==22820==      possibly lost: 0 bytes in 0 blocks
==22820==    still reachable: 32 bytes in 1 blocks
==22820==         suppressed: 0 bytes in 0 blocks
==22820== Reachable blocks (those to which a pointer was found) are not shown.
==22820== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==22820== 
==22820== For counts of detected and suppressed errors, rerun with: -v
==22820== ERROR SUMMARY: 3 errors from 3 contexts (suppressed: 0 from 0)

No leaks without the PKCS11 engine configured in OpenSSL config

$ valgrind --tool=memcheck --leak-check=full curl https://google.com
==22803== Memcheck, a memory error detector
==22803== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==22803== Using Valgrind-3.13.0 and LibVEX; rerun with -h for copyright info
==22803== Command: curl https://google.com
==22803== 
<HTML><HEAD><meta http-equiv="content-type" content="text/html;charset=utf-8">
<TITLE>301 Moved</TITLE></HEAD><BODY>
<H1>301 Moved</H1>
The document has moved
<A HREF="https://www.google.com/">here</A>.
</BODY></HTML>
==22803== 
==22803== HEAP SUMMARY:
==22803==     in use at exit: 0 bytes in 0 blocks
==22803==   total heap usage: 32,219 allocs, 32,219 frees, 3,100,859 bytes allocated
==22803== 
==22803== All heap blocks were freed -- no leaks are possible
==22803== 
==22803== For counts of detected and suppressed errors, rerun with: -v
==22803== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
@dengert
Copy link
Member

dengert commented Sep 28, 2020

This is not clear if this is a libp11 problem or in OpenSSL problem with the config file.
I don't get any memory leaks on xubuntu-20.04 with the above command, or when running
OPENSSL_CONF=pkcs11.openssl.conf valgrind --tool=memcheck --leak-check=full curl https://google.c
where pkcs11.openssl.conf contains

[ openssl_def ]
engines = engine_section

[ engine_section ]

pkcs11 = pkcs11_section

[ pkcs11_section ]

engine_id = pkcs11
dynamic_path = /opt/smartcard/lib/engines/libpkcs11.so
MODULE_PATH = /opt/smartcard/lib/opensc-pkcs11.so
init = 0 
VERBOSE = EMPTY

If valgrind prints lines like: ==22820== by 0xB8FDB02: ??? it means it can not find the debugging symbol tables for modules that have been unloaded. So I sometime run valgrind with: LD_PRELOAD=/opt/smartcard/lib/libno-dlclose.so
where libno-dlclose.so is made from no-dlcose.c:

/*
 * preload to force dlopened libs to not be closed
 * Use with LD_PRELOAD  with valgrind
 * Doug Engert <deengert@gmail.com>
 */

#include <dlfcn.h>

int dlclose(void *handle)
{
    return 0;
}

@vgottardi2
Copy link
Author

Thanks Doug for the tip about valgrind ???. I also discovered that valgrind 3.14 supports "--keep-debuginfo=yes" for the same purpose.
My output was from Ubuntu 18. I'll see if I can reproduce with 20.
Here's a trace without ??? from my Yocto build.

==513== 60 bytes in 1 blocks are definitely lost in loss record 2 of 5
==513==    at 0x48179A0: malloc (vg_replace_malloc.c:309)
==513==    by 0x4B17CB7: CRYPTO_zalloc (mem.c:230)
==513==    by 0x4ACE3A7: EC_KEY_METHOD_new (ec_kmeth.c:157)
==513==    by 0x5186DBD: PKCS11_get_ec_key_method (p11_ec.c:716)
==513==    by 0x5181FE9: bind_helper (eng_front.c:224)
==513==    by 0x5181FE9: bind_fn (eng_front.c:250)
==513==    by 0x5181FE9: bind_engine (eng_front.c:258)
==513==    by 0x4AFFB9F: dynamic_load (eng_dyn.c:480)
==513==    by 0x4AFFB9F: dynamic_ctrl (eng_dyn.c:336)
==513==    by 0x4AFF695: ENGINE_ctrl_cmd_string (eng_ctrl.c:289)
==513==    by 0x4B00B99: ENGINE_by_id (eng_list.c:328)
==513==    by 0x4AFF111: int_engine_configure (eng_cnf.c:100)
==513==    by 0x4AFF111: int_engine_module_init (eng_cnf.c:171)
==513==    by 0x4AAE06D: module_init (conf_mod.c:312)
==513==    by 0x4AAE06D: module_run (conf_mod.c:171)
==513==    by 0x4AAE06D: CONF_modules_load (conf_mod.c:102)
==513==    by 0x4AAE427: CONF_modules_load_file (conf_mod.c:138)
==513==    by 0x4863219: Curl_ossl_init (in /usr/lib/libcurl.so.4.6.0)
==513==
==513== 78 (60 direct, 18 indirect) bytes in 1 blocks are definitely lost in loss record 3 of 5
==513==    at 0x48179A0: malloc (vg_replace_malloc.c:309)
==513==    by 0x4B352E1: RSA_meth_dup (rsa_meth.c:42)
==513==    by 0x5186619: PKCS11_get_rsa_method (p11_rsa.c:493)
==513==    by 0x5181FD9: bind_helper (eng_front.c:219)
==513==    by 0x5181FD9: bind_fn (eng_front.c:250)
==513==    by 0x5181FD9: bind_engine (eng_front.c:258)
==513==    by 0x4AFFB9F: dynamic_load (eng_dyn.c:480)
==513==    by 0x4AFFB9F: dynamic_ctrl (eng_dyn.c:336)
==513==    by 0x4AFF695: ENGINE_ctrl_cmd_string (eng_ctrl.c:289)
==513==    by 0x4B00B99: ENGINE_by_id (eng_list.c:328)
==513==    by 0x4AFF111: int_engine_configure (eng_cnf.c:100)
==513==    by 0x4AFF111: int_engine_module_init (eng_cnf.c:171)
==513==    by 0x4AAE06D: module_init (conf_mod.c:312)
==513==    by 0x4AAE06D: module_run (conf_mod.c:171)
==513==    by 0x4AAE06D: CONF_modules_load (conf_mod.c:102)
==513==    by 0x4AAE427: CONF_modules_load_file (conf_mod.c:138)
==513==    by 0x4863219: Curl_ossl_init (in /usr/lib/libcurl.so.4.6.0)
==513==
==513== 132 bytes in 1 blocks are definitely lost in loss record 4 of 5
==513==    at 0x48179A0: malloc (vg_replace_malloc.c:309)
==513==    by 0x4B17CB7: CRYPTO_zalloc (mem.c:230)
==513==    by 0x4B1254F: EVP_PKEY_meth_new (pmeth_lib.c:174)
==513==    by 0x5187679: pkcs11_pkey_method_rsa (p11_pkey.c:518)
==513==    by 0x5187679: PKCS11_pkey_meths (p11_pkey.c:703)
==513==    by 0x4B02399: engine_pkey_meths_free (tb_pkmeth.c:109)
==513==    by 0x4B0047D: engine_free_util (eng_lib.c:87)
==513==    by 0x4B009D9: engine_list_remove (eng_list.c:125)
==513==    by 0x4B009D9: ENGINE_remove (eng_list.c:239)
==513==    by 0x4B00A59: engine_list_cleanup (eng_list.c:38)
==513==    by 0x4B00333: engine_cleanup_cb_free (eng_lib.c:162)
==513==    by 0x4B49A3B: OPENSSL_sk_pop_free (stack.c:368)
==513==    by 0x4B0056D: sk_ENGINE_CLEANUP_ITEM_pop_free (eng_local.h:54)
==513==    by 0x4B0056D: engine_cleanup_int (eng_lib.c:169)
==513==    by 0x4B14AF7: OPENSSL_cleanup (init.c:601)
==513==    by 0x4B14AF7: OPENSSL_cleanup (init.c:497)
==513==
==513== 132 bytes in 1 blocks are definitely lost in loss record 5 of 5
==513==    at 0x48179A0: malloc (vg_replace_malloc.c:309)
==513==    by 0x4B17CB7: CRYPTO_zalloc (mem.c:230)
==513==    by 0x4B1254F: EVP_PKEY_meth_new (pmeth_lib.c:174)
==513==    by 0x51876CB: pkcs11_pkey_method_ec (p11_pkey.c:662)
==513==    by 0x51876CB: PKCS11_pkey_meths (p11_pkey.c:711)
==513==    by 0x4B02399: engine_pkey_meths_free (tb_pkmeth.c:109)
==513==    by 0x4B0047D: engine_free_util (eng_lib.c:87)
==513==    by 0x4B009D9: engine_list_remove (eng_list.c:125)
==513==    by 0x4B009D9: ENGINE_remove (eng_list.c:239)
==513==    by 0x4B00A59: engine_list_cleanup (eng_list.c:38)
==513==    by 0x4B00333: engine_cleanup_cb_free (eng_lib.c:162)
==513==    by 0x4B49A3B: OPENSSL_sk_pop_free (stack.c:368)
==513==    by 0x4B0056D: sk_ENGINE_CLEANUP_ITEM_pop_free (eng_local.h:54)
==513==    by 0x4B0056D: engine_cleanup_int (eng_lib.c:169)
==513==    by 0x4B14AF7: OPENSSL_cleanup (init.c:601)
==513==    by 0x4B14AF7: OPENSSL_cleanup (init.c:497)
==513==
==513== LEAK SUMMARY:
==513==    definitely lost: 384 bytes in 4 blocks
==513==    indirectly lost: 18 bytes in 1 blocks
==513==      possibly lost: 0 bytes in 0 blocks
==513==    still reachable: 0 bytes in 0 blocks
==513==         suppressed: 0 bytes in 0 blocks

@dengert
Copy link
Member

dengert commented Sep 29, 2020

What versions of libp11 and openssl are you using?

These are the lines that look strange

==513==    by 0x4B1254F: EVP_PKEY_meth_new (pmeth_lib.c:174)
==513==    by 0x5187679: pkcs11_pkey_method_rsa (p11_pkey.c:518)
==513==    by 0x5187679: PKCS11_pkey_meths (p11_pkey.c:703)
==513==    by 0x4B02399: engine_pkey_meths_free (tb_pkmeth.c:109)
==513==    by 0x4B0047D: engine_free_util (eng_lib.c:87)

This is during cleanup and and p11_pkey.c:518 is calling EVP_PKEY_meth_new.
looks like it is fixed in: 66ebbaa

@vgottardi2
Copy link
Author

libp11 is latest from master
openssl is 1.1.1g

@dengert
Copy link
Member

dengert commented Sep 29, 2020

Just to make sure, check the opensc.cnf file. The one you sent did not list lines line these (with your path):

dynamic_path = /opt/smartcard/lib/engines/libpkcs11.so
MODULE_PATH = /opt/smartcard/lib/opensc-pkcs11.so

It may have been picking up some older version.

@vgottardi2
Copy link
Author

On my board, this what I have in my openssl.cnf file. It's definitely the right version of libp11. The line numbers from the trace perfectly match the source

openssl_conf = openssl_init

[openssl_init]
engines=engine_section

[engine_section]
pkcs11 = pkcs11_section

[pkcs11_section]
engine_id = pkcs11
dynamic_path = /usr/lib/engines-1.1/pkcs11.so
MODULE_PATH = /usr/lib/libcryptoauth.so
init = 0

It could be curl that is doing something funky. I have curl 7.66.0.
I'll try with a newer version.

@dengert
Copy link
Member

dengert commented Sep 30, 2020

Are /usr/lib/engines-1.1/pkcs11.so and /usr/lib/libcryptoauth.so are not present on my Xubuntu-18.04
Did you build libp11 and install /usr/lib/engines-1.1/pkcs11.so?

In master is also 5aa56b4 that deals with freeing new method.
I am at my limits on this.
Maybe @mtrojnar needs to look at this closer.

@vgottardi2
Copy link
Author

The Yocto recipe installs it in /usr/lib/engines-1.1/pkcs11.so.
The first trace is from my Ubuntu 18.04. The second trace is form my Yocto build. Sorry for the confusion.
Thanks a lot for the help. Let's put it on hold until I find a clean way to reproduce it.

@vgottardi2
Copy link
Author

Full steps to reproduce in Ubuntu 20.04
Start a throw-away install of Ubuntu. I use https://multipass.run/. Same results with Ubuntu Desktop

multipass launch --name test-p11
multipass shell test-p11

Build and install libp11

sudo apt install git build-essential autoconf libtool pkg-config valgrind libssl-dev --yes

git clone https://github.com/OpenSC/libp11.git
cd libp11
./bootstrap
./configure
make 
sudo make install

Optional: install debug symbols

echo "deb http://ddebs.ubuntu.com $(lsb_release -cs) main restricted universe multiverse" | sudo tee -a /etc/apt/sources.list.d/ddebs.list
sudo apt install ubuntu-dbgsym-keyring
sudo apt-get update
sudo apt install libssl1.1-dbgsym openssl-dbgsym libcurl4-dbgsym

Load engine

$ valgrind --tool=memcheck --leak-check=full --keep-debuginfo=yes openssl engine -t pkcs11
==24499== Memcheck, a memory error detector
==24499== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==24499== Using Valgrind-3.15.0 and LibVEX; rerun with -h for copyright info
==24499== Command: openssl engine -t pkcs11
==24499==
(pkcs11) pkcs11 engine
     [ available ]
==24499==
==24499== HEAP SUMMARY:
==24499==     in use at exit: 770 bytes in 5 blocks
==24499==   total heap usage: 3,991 allocs, 3,986 frees, 152,245 bytes allocated
==24499==
==24499== 120 bytes in 1 blocks are definitely lost in loss record 2 of 5
==24499==    at 0x483B7F3: malloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
==24499==    by 0x4A5F8CD: CRYPTO_zalloc (mem.c:230)
==24499==    by 0x49ED0BD: EC_KEY_METHOD_new (ec_kmeth.c:157)
==24499==    by 0x51E80CA: PKCS11_get_ec_key_method (p11_ec.c:716)
==24499==    by 0x51E0906: bind_helper (eng_front.c:224)
==24499==    by 0x51E0906: bind_fn (eng_front.c:250)
==24499==    by 0x51E0906: bind_engine (eng_front.c:258)
==24499==    by 0x4A36D12: dynamic_load (eng_dyn.c:480)
==24499==    by 0x4A36D12: dynamic_ctrl (eng_dyn.c:336)
==24499==    by 0x4A3649A: ENGINE_ctrl_cmd_string (eng_ctrl.c:327)
==24499==    by 0x4A38654: ENGINE_by_id (eng_list.c:328)
==24499==    by 0x15131C: engine_main (engine.c:380)
==24499==    by 0x1567C5: do_cmd (openssl.c:570)
==24499==    by 0x1408F9: main (openssl.c:189)
==24499==
==24499== 138 (120 direct, 18 indirect) bytes in 1 blocks are definitely lost in loss record 3 of 5
==24499==    at 0x483B7F3: malloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
==24499==    by 0x4A90473: RSA_meth_dup (rsa_meth.c:42)
==24499==    by 0x51E7429: PKCS11_get_rsa_method (p11_rsa.c:483)
==24499==    by 0x51E08EE: bind_helper (eng_front.c:219)
==24499==    by 0x51E08EE: bind_fn (eng_front.c:250)
==24499==    by 0x51E08EE: bind_engine (eng_front.c:258)
==24499==    by 0x4A36D12: dynamic_load (eng_dyn.c:480)
==24499==    by 0x4A36D12: dynamic_ctrl (eng_dyn.c:336)
==24499==    by 0x4A3649A: ENGINE_ctrl_cmd_string (eng_ctrl.c:327)
==24499==    by 0x4A38654: ENGINE_by_id (eng_list.c:328)
==24499==    by 0x15131C: engine_main (engine.c:380)
==24499==    by 0x1567C5: do_cmd (openssl.c:570)
==24499==    by 0x1408F9: main (openssl.c:189)
==24499==
==24499== 256 bytes in 1 blocks are definitely lost in loss record 4 of 5
==24499==    at 0x483B7F3: malloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
==24499==    by 0x4A5F8CD: CRYPTO_zalloc (mem.c:230)
==24499==    by 0x4A588E3: EVP_PKEY_meth_new (pmeth_lib.c:179)
==24499==    by 0x51E8F23: pkcs11_pkey_method_rsa (p11_pkey.c:518)
==24499==    by 0x51E8F23: PKCS11_pkey_meths (p11_pkey.c:703)
==24499==    by 0x4A3AB9B: engine_pkey_meths_free (tb_pkmeth.c:109)
==24499==    by 0x4A37AE8: engine_free_util (eng_lib.c:87)
==24499==    by 0x4A38304: engine_list_remove (eng_list.c:125)
==24499==    by 0x4A38304: ENGINE_remove (eng_list.c:239)
==24499==    by 0x4A383DC: engine_list_cleanup (eng_list.c:38)
==24499==    by 0x4A378C9: engine_cleanup_cb_free (eng_lib.c:162)
==24499==    by 0x4AC2CEF: OPENSSL_sk_pop_free (stack.c:368)
==24499==    by 0x4A37C2F: sk_ENGINE_CLEANUP_ITEM_pop_free (eng_local.h:54)
==24499==    by 0x4A37C2F: engine_cleanup_int (eng_lib.c:169)
==24499==    by 0x4A5B461: OPENSSL_cleanup (init.c:601)
==24499==    by 0x4A5B461: OPENSSL_cleanup (init.c:497)
==24499==
==24499== 256 bytes in 1 blocks are definitely lost in loss record 5 of 5
==24499==    at 0x483B7F3: malloc (in /usr/lib/x86_64-linux-gnu/valgrind/vgpreload_memcheck-amd64-linux.so)
==24499==    by 0x4A5F8CD: CRYPTO_zalloc (mem.c:230)
==24499==    by 0x4A588E3: EVP_PKEY_meth_new (pmeth_lib.c:179)
==24499==    by 0x51E8FB1: pkcs11_pkey_method_ec (p11_pkey.c:662)
==24499==    by 0x51E8FB1: PKCS11_pkey_meths (p11_pkey.c:711)
==24499==    by 0x4A3AB9B: engine_pkey_meths_free (tb_pkmeth.c:109)
==24499==    by 0x4A37AE8: engine_free_util (eng_lib.c:87)
==24499==    by 0x4A38304: engine_list_remove (eng_list.c:125)
==24499==    by 0x4A38304: ENGINE_remove (eng_list.c:239)
==24499==    by 0x4A383DC: engine_list_cleanup (eng_list.c:38)
==24499==    by 0x4A378C9: engine_cleanup_cb_free (eng_lib.c:162)
==24499==    by 0x4AC2CEF: OPENSSL_sk_pop_free (stack.c:368)
==24499==    by 0x4A37C2F: sk_ENGINE_CLEANUP_ITEM_pop_free (eng_local.h:54)
==24499==    by 0x4A37C2F: engine_cleanup_int (eng_lib.c:169)
==24499==    by 0x4A5B461: OPENSSL_cleanup (init.c:601)
==24499==    by 0x4A5B461: OPENSSL_cleanup (init.c:497)
==24499==
==24499== LEAK SUMMARY:
==24499==    definitely lost: 752 bytes in 4 blocks
==24499==    indirectly lost: 18 bytes in 1 blocks
==24499==      possibly lost: 0 bytes in 0 blocks
==24499==    still reachable: 0 bytes in 0 blocks
==24499==         suppressed: 0 bytes in 0 blocks
==24499==
==24499== For lists of detected and suppressed errors, rerun with: -s
==24499== ERROR SUMMARY: 4 errors from 4 contexts (suppressed: 0 from 0)

@dengert
Copy link
Member

dengert commented Oct 2, 2020

What I am seeing is a difference of valgrind versions. Your output shows version 3.15.0 which is on Ubuntu 20.04. Ubuntu 18.04 has 3.13.0. and does not show the leaks, and has:

==13176== HEAP SUMMARY:
==13176==     in use at exit: 2,354 bytes in 10 blocks
==13176==   total heap usage: 4,086 allocs, 4,076 frees, 155,330 bytes allocated
==13176== 
==13176== Searching for pointers to 10 not-freed blocks
==13176== Checked 191,752 bytes
==13176== 
==13176== LEAK SUMMARY:
==13176==    definitely lost: 0 bytes in 0 blocks
==13176==    indirectly lost: 0 bytes in 0 blocks
==13176==      possibly lost: 0 bytes in 0 blocks
==13176==    still reachable: 2,354 bytes in 10 blocks
==13176==         suppressed: 0 bytes in 0 blocks
==13176== Reachable blocks (those to which a pointer was found) are not shown.
==13176== To see them, rerun with: --leak-check=full --show-leak-kinds=all
==13176== 
==13176== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)
==13176== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

If I add --show-leak-kinds=all

It shows the 4 libp11 entries for PKCS11_get_rsa_method, PKCS11_get_ec_key_method, pkcs11_pkey_method_rsa and pkcs11_pkey_method_ec and some dl_open lost blocks. but still shows:

ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

So there is a problem. which looks like OpenSSL is trying to free the methods, but libp11 saved these in static pointers. libp11 may have allocated the methods a second time when the process is being shut down.

dengert added a commit to dengert/libp11 that referenced this issue Oct 4, 2020
"static *_METHOD *ops = NULL;" statements moved from inside functions
to outside and opts renamed. Each now has a *_free routine.

The *_free routines are called from ctx_destroy as engine is being destroyed.

Fixes issue OpenSC#358

Please enter the commit message for your changes. Lines starting
 On branch p11-free-methods
 Changes to be committed:
	modified:   src/eng_back.c
	modified:   src/libp11.h
	modified:   src/p11_ec.c
	modified:   src/p11_pkey.c
	modified:   src/p11_rsa.c
@dengert
Copy link
Member

dengert commented Oct 4, 2020

Give #359 a try. On Ubuntu 20.04 shows no errors with this command:

valgrind -v --tool=memcheck --leak-check=full  --keep-debuginfo=yes --show-leak-kinds=all openssl engine -t -tt -vvvv pkcs11
--9790-- Scanned 1,213 ExeContexts, archived 29 ExeContexts
==9790== 
==9790== HEAP SUMMARY:
==9790==     in use at exit: 0 bytes in 0 blocks
==9790==   total heap usage: 4,011 allocs, 4,011 frees, 152,609 bytes allocated
==9790== 
==9790== All heap blocks were freed -- no leaks are possible
==9790== 
==9790== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

@mtrojnar
Copy link
Member

mtrojnar commented Oct 4, 2020

@vgottardi2 Do you use libp11 on an operating system that does not automatically release memory at application exit?

@vgottardi2
Copy link
Author

@dengert, yes, #359 fixes the issue. Thank you!

@mtrojnar, I'm using Linux. You're right, these leaks would not be such a huge issue since the typical application only initializes the context once.
Thanks for merging #350. That one is more serious because it would leak repeatedly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants