regression: tpm2-pkcs11-1.9.1 breaks OpenVPN PKCS#11 with TPM functionality

[maratik123]

With tpm2-pkcs11-1.9.0 PKCS#11 part of connection initialization in openvpn.log looks like this:

...
2025-01-16 15:35:26 us=998787 OpenVPN 2.6.9 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD]
2025-01-16 15:35:26 us=998801 library versions: OpenSSL 3.3.2 3 Sep 2024, LZO 2.10
2025-01-16 15:35:26 us=999935 PKCS#11: pkcs11_initialize - entered
2025-01-16 15:35:27 us=128 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=163 PKCS#11: pkcs11h_setProperty entry property='1', value=0x7fffb6d928ac, value_size=4
2025-01-16 15:35:27 us=187 PKCS#11: Setting property 1=0x0
2025-01-16 15:35:27 us=209 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=230 PKCS#11: pkcs11h_setProperty entry property='7', value=0x7fffb6d928a0, value_size=8
2025-01-16 15:35:27 us=250 PKCS#11: Setting property 7=0x0
2025-01-16 15:35:27 us=271 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=292 PKCS#11: pkcs11h_setProperty entry property='6', value=0x7fffb6d928a8, value_size=8
2025-01-16 15:35:27 us=312 PKCS#11: Setting property 6=0x55c0448f0950
2025-01-16 15:35:27 us=332 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=353 PKCS#11: pkcs11h_setProperty entry property='9', value=0x7fffb6d928a0, value_size=8
2025-01-16 15:35:27 us=373 PKCS#11: Setting property 9=0x55c06df95148
2025-01-16 15:35:27 us=393 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=413 PKCS#11: pkcs11h_setProperty entry property='8', value=0x7fffb6d928a8, value_size=8
2025-01-16 15:35:27 us=433 PKCS#11: Setting property 8=0x55c0448f07b0
2025-01-16 15:35:27 us=453 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=474 PKCS#11: pkcs11h_setProperty entry property='10', value=0x7fffb6d928ac, value_size=4
2025-01-16 15:35:27 us=494 PKCS#11: Setting property 10=0x1
2025-01-16 15:35:27 us=514 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=535 PKCS#11: pkcs11h_setProperty entry property='11', value=0x7fffb6d928ac, value_size=4
2025-01-16 15:35:27 us=555 PKCS#11: Setting property 11=0xffffffff
2025-01-16 15:35:27 us=575 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=595 PKCS#11: pkcs11_initialize - return 0-'CKR_OK'
2025-01-16 15:35:27 us=616 PKCS#11: pkcs11_addProvider - entered - provider='/usr/lib64/pkcs11/libtpm2_pkcs11.so', private_mode=00000000
2025-01-16 15:35:27 us=636 PKCS#11: Adding PKCS#11 provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:35:27 us=656 PKCS#11: pkcs11h_registerProvider entry version='1.29.0', reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:35:27 us=676 PKCS#11: Register provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:35:27 us=697 PKCS#11: pkcs11h_registerProvider Provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:35:27 us=718 PKCS#11: Provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so' registered rv=0-'CKR_OK'
2025-01-16 15:35:27 us=739 PKCS#11: pkcs11h_registerProvider return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=760 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='0', value=0x55c06df94fd8, value_size=36
2025-01-16 15:35:27 us=781 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:location=/usr/lib64/pkcs11/libtpm2_pkcs11.so
2025-01-16 15:35:27 us=803 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=824 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='1', value=0x7fffb6d928b0, value_size=4
2025-01-16 15:35:27 us=845 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:allow_protected_auth=0x0
2025-01-16 15:35:27 us=866 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=886 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='2', value=0x7fffb6d928ac, value_size=4
2025-01-16 15:35:27 us=907 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:mask_private_mode=0x0
2025-01-16 15:35:27 us=927 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=948 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='5', value=0x7fffb6d928b4, value_size=4
2025-01-16 15:35:27 us=989 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:cert_is_private=0x0
2025-01-16 15:35:27 us=1015 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=1037 PKCS#11: pkcs11h_initializeProvider entry pid=26425, reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:35:27 us=1057 PKCS#11: Initializing provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
WARNING: Getting tokens from fapi backend failed.
2025-01-16 15:35:27 us=93257 PKCS#11: pkcs11h_initializeProvider Provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so' manufacturerID 'tpm2-software.github.io'
2025-01-16 15:35:27 us=93449 PKCS#11: _pkcs11h_slotevent_notify entry
2025-01-16 15:35:27 us=93464 PKCS#11: _pkcs11h_slotevent_notify return
2025-01-16 15:35:27 us=93474 PKCS#11: pkcs11h_initializeProvider return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=93484 PKCS#11: pkcs11_addProvider - return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=93577 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2025-01-16 15:35:27 us=93601 PO_INIT maxevents=5 flags=0x00000002
2025-01-16 15:35:27 us=93708 xkey_provider: In xkey_provider_init: entry
2025-01-16 15:35:27 us=95858 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=95879 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=95902 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=95915 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=95932 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=95945 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=95965 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=95977 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=95998 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96011 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96027 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96039 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96053 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96065 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96079 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96091 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96105 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96117 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96132 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96144 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96162 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96175 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96190 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96202 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96216 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96227 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96242 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96253 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96267 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96279 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96295 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96307 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96325 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96337 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96351 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96363 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96377 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96389 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96426 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96439 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96466 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=96478 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96742 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96755 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96770 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96782 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96796 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96808 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96823 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96836 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96851 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96863 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96877 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96889 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96903 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96915 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96934 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96946 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96961 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96974 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=96988 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=96999 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97012 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=97023 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97036 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=97047 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97061 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=97071 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97086 xkey_provider: In query_operation: op = 1
2025-01-16 15:35:27 us=97097 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97152 xkey_provider: In query_operation: op = 12
2025-01-16 15:35:27 us=97205 xkey_provider: In query_operation: op = 11
2025-01-16 15:35:27 us=97217 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97230 xkey_provider: In query_operation: op = 11
2025-01-16 15:35:27 us=97241 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97254 xkey_provider: In query_operation: op = 12
2025-01-16 15:35:27 us=97437 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97538 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97553 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97570 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97602 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97616 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97633 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97649 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97665 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=97781 xkey_provider: In query_operation: op = 5
2025-01-16 15:35:27 us=97793 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97811 xkey_provider: In query_operation: op = 5
2025-01-16 15:35:27 us=97822 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97847 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=97868 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=97881 xkey_provider: In query_operation: op = 2
2025-01-16 15:35:27 us=97901 xkey_provider: In query_operation: op not supported
2025-01-16 15:35:27 us=98068 PKCS#11: tls_ctx_use_pkcs11 - entered - ssl_ctx=0x7fffb6d93390, pkcs11_id_management=0, pkcs11_id='STMicro//0000000000000000/tpm\x2Dtoken/66346566326638363665336238343537'
2025-01-16 15:35:27 us=98078 PKCS#11: pkcs11h_certificate_deserializeCertificateId entry p_certificate_id=0x7fffb6d90310, sz='STMicro//0000000000000000/tpm\x2Dtoken/66346566326638363665336238343537'
2025-01-16 15:35:27 us=98087 PKCS#11: _pkcs11h_certificate_newCertificateId entry p_certificate_id=0x7fffb6d902c8
2025-01-16 15:35:27 us=98096 PKCS#11: _pkcs11h_certificate_newCertificateId return rv=0-'CKR_OK', *p_certificate_id=0x55c06e0a8480
2025-01-16 15:35:27 us=98104 PKCS#11: pkcs11h_token_deserializeTokenId entry p_token_id=0x55c06e0a8480, sz='STMicro//0000000000000000/tpm\x2Dtoken'
2025-01-16 15:35:27 us=98112 PKCS#11: _pkcs11h_token_newTokenId entry p_token_id=0x7fffb6d90218
2025-01-16 15:35:27 us=98121 PKCS#11: _pkcs11h_token_newTokenId return rv=0-'CKR_OK', *p_token_id=0x55c06e0a88b0
2025-01-16 15:35:27 us=98132 PKCS#11: pkcs11h_token_deserializeTokenId return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98142 PKCS#11: pkcs11h_certificate_deserializeCertificateId return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98152 PKCS#11: pkcs11h_certificate_create entry certificate_id=0x55c06e0a8480, user_data=(nil), mask_prompt=00000007, pin_cache_period=-1, p_certificate=0x7fffb6d90318
2025-01-16 15:35:27 us=98162 PKCS#11: pkcs11h_certificate_duplicateCertificateId entry to=0x55c06e0a8d20 form=0x55c06e0a8480
2025-01-16 15:35:27 us=98171 PKCS#11: pkcs11h_certificate_duplicateCertificateId return rv=0-'CKR_OK', *to=0x55c06e0a8db0
2025-01-16 15:35:27 us=98179 PKCS#11: _pkcs11h_session_getSessionByTokenId entry token_id=0x55c06e0a91e0, p_session=0x55c06e0a8d38
2025-01-16 15:35:27 us=98187 PKCS#11: Creating a new session
2025-01-16 15:35:27 us=98195 PKCS#11: pkcs11h_token_duplicateTokenId entry to=0x55c06e0a9688 form=0x55c06e0a91e0
2025-01-16 15:35:27 us=98203 PKCS#11: pkcs11h_token_duplicateTokenId return rv=0-'CKR_OK', *to=0x55c06e0a9a90
2025-01-16 15:35:27 us=98211 PKCS#11: _pkcs11h_session_getSessionByTokenId return rv=0-'CKR_OK', *p_session=0x55c06e0a9670
2025-01-16 15:35:27 us=98219 PKCS#11: pkcs11h_certificate_create return rv=0-'CKR_OK' *p_certificate=0x55c06e0a8d20
2025-01-16 15:35:27 us=98227 PKCS#11: pkcs11h_openssl_getX509 - entry certificate=0x55c06e0a8d20
2025-01-16 15:35:27 us=98260 PKCS#11: pkcs11h_certificate_getCertificateBlob entry certificate=0x55c06e0a8d20, certificate_blob=(nil), *p_certificate_blob_size=0000000000000000
2025-01-16 15:35:27 us=98268 PKCS#11: __pkcs11h_certificate_loadCertificate entry certificate=0x55c06e0a8d20
2025-01-16 15:35:27 us=98276 PKCS#11: _pkcs11h_session_validate entry session=0x55c06e0a9670
2025-01-16 15:35:27 us=98284 PKCS#11: _pkcs11h_session_validate return rv=179-'CKR_SESSION_HANDLE_INVALID'
2025-01-16 15:35:27 us=98292 PKCS#11: __pkcs11h_certificate_loadCertificate return rv=179-'CKR_SESSION_HANDLE_INVALID'
2025-01-16 15:35:27 us=98300 PKCS#11: _pkcs11h_certificate_resetSession entry certificate=0x55c06e0a8d20, public_only=1, session_mutex_locked=0
2025-01-16 15:35:27 us=98309 PKCS#11: _pkcs11h_session_login entry session=0x55c06e0a9670, is_publicOnly=1, readonly=1, user_data=(nil), mask_prompt=00000007
2025-01-16 15:35:27 us=98316 PKCS#11: _pkcs11h_session_logout entry session=0x55c06e0a9670
2025-01-16 15:35:27 us=98324 PKCS#11: _pkcs11h_session_logout return
2025-01-16 15:35:27 us=98332 PKCS#11: _pkcs11h_session_reset entry session=0x55c06e0a9670, user_data=(nil), mask_prompt=00000007, p_slot=0x7fffb6d90100
2025-01-16 15:35:27 us=98340 PKCS#11: _pkcs11h_session_reset Expected token manufacturerID='STMicro' model='', serialNumber='0000000000000000', label='tpm-token'
2025-01-16 15:35:27 us=98348 PKCS#11: _pkcs11h_session_getSlotList entry provider=0x55c06dfe2740, token_present=1, pSlotList=0x7fffb6d8ffc8, pulCount=0x7fffb6d8ffd0
2025-01-16 15:35:27 us=98360 PKCS#11: _pkcs11h_session_getSlotList return rv=0-'CKR_OK' *pulCount=2
2025-01-16 15:35:27 us=98381 PKCS#11: _pkcs11h_token_getTokenId entry p_token_id=0x7fffb6d8ffd8
2025-01-16 15:35:27 us=98389 PKCS#11: _pkcs11h_token_newTokenId entry p_token_id=0x7fffb6d8ff50
2025-01-16 15:35:27 us=98397 PKCS#11: _pkcs11h_token_newTokenId return rv=0-'CKR_OK', *p_token_id=0x55c06e0aa000
2025-01-16 15:35:27 us=98405 PKCS#11: _pkcs11h_token_getTokenId return rv=0-'CKR_OK', *p_token_id=0x55c06e0aa000
2025-01-16 15:35:27 us=98413 PKCS#11: _pkcs11h_session_reset Found token manufacturerID='STMicro' model='', serialNumber='0000000000000000', label='tpm-token'
2025-01-16 15:35:27 us=98421 PKCS#11: pkcs11h_token_freeTokenId entry certificate_id=0x55c06e0aa000
2025-01-16 15:35:27 us=98428 PKCS#11: pkcs11h_token_freeTokenId return
2025-01-16 15:35:27 us=98436 PKCS#11: _pkcs11h_session_reset return rv=0-'CKR_OK', *p_slot=1
2025-01-16 15:35:27 us=98445 PKCS#11: _pkcs11h_session_login return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98453 PKCS#11: _pkcs11h_certificate_resetSession return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98460 PKCS#11: __pkcs11h_certificate_loadCertificate entry certificate=0x55c06e0a8d20
2025-01-16 15:35:27 us=98467 PKCS#11: _pkcs11h_session_validate entry session=0x55c06e0a9670
2025-01-16 15:35:27 us=98476 PKCS#11: _pkcs11h_session_validate session->pin_expire_time=0, time=1737030927
2025-01-16 15:35:27 us=98483 PKCS#11: _pkcs11h_session_validate return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98491 PKCS#11: _pkcs11h_session_findObjects entry session=0x55c06e0a9670, filter=0x7fffb6d90200, filter_attrs=2, p_objects=0x7fffb6d901d0, p_objects_found=0x7fffb6d901d8
2025-01-16 15:35:27 us=98505 PKCS#11: _pkcs11h_session_findObjects return rv=0-'CKR_OK', *p_objects_found=1
2025-01-16 15:35:27 us=98513 PKCS#11: _pkcs11h_session_getObjectAttributes entry session=0x55c06e0a9670, object=3, attrs=0x7fffb6d901e0, count=1
2025-01-16 15:35:27 us=98523 PKCS#11: _pkcs11h_session_getObjectAttributes return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=98532 PKCS#11: _pkcs11h_certificate_isBetterCertificate entry current=(nil), current_size=0000000000000000, newone=0x55c06e0aa080, newone_size=00000000000004db
2025-01-16 15:35:27 us=98540 PKCS#11: _pkcs11h_certificate_isBetterCertificate return is_better=1
2025-01-16 15:35:27 us=98550 PKCS#11: _pkcs11h_session_freeObjectAttributes entry attrs=0x7fffb6d901e0, count=1
2025-01-16 15:35:27 us=98558 PKCS#11: _pkcs11h_session_freeObjectAttributes return
2025-01-16 15:35:27 us=98566 PKCS#11: __pkcs11h_certificate_updateCertificateIdDescription entry certificate_id=0x55c06e0a8db0
2025-01-16 15:35:27 us=99060 PKCS#11: __pkcs11h_openssl_ex_data_free entered - parent=0x55c06e0b1e50, ptr=(nil), ad=0x55c06e0b1ee0, idx=1, argl=0, argp=0x7f47c5236d12
2025-01-16 15:35:27 us=99082 PKCS#11: __pkcs11h_certificate_updateCertificateIdDescription return displayName='**discarded** on tpm-token'
2025-01-16 15:35:27 us=99090 PKCS#11: __pkcs11h_certificate_loadCertificate return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=99098 PKCS#11: pkcs11h_certificate_getCertificateBlob return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=99109 PKCS#11: pkcs11h_certificate_getCertificateBlob entry certificate=0x55c06e0a8d20, certificate_blob=0x55c06e0b2480, *p_certificate_blob_size=00000000000004db
2025-01-16 15:35:27 us=99117 PKCS#11: pkcs11h_certificate_getCertificateBlob return rv=0-'CKR_OK'
2025-01-16 15:35:27 us=99210 PKCS#11: pkcs11h_openssl_getX509 - return rv=0-'CKR_OK', x509=0x55c06e0a9710
2025-01-16 15:35:27 us=99221 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=99238 xkey_provider: In keymgmt_new: entry
2025-01-16 15:35:27 us=99248 xkey_provider: In keydata_new: entry
2025-01-16 15:35:27 us=99259 xkey_provider: In rsa_keymgmt_import: entry
2025-01-16 15:35:27 us=99270 xkey_provider: In keymgmt_import: entry
2025-01-16 15:35:27 us=99280 xkey_provider: In keymgmt_import: importing external key
2025-01-16 15:35:27 us=99291 xkey_provider: In keymgmt_import_helper: entry
2025-01-16 15:35:27 us=99312 xkey_provider: In keymgmt_import_helper: imported external RSA key
2025-01-16 15:35:27 us=99340 xkey_provider: In keymgmt_get_params: entry
2025-01-16 15:35:27 us=99394 xkey_provider: In keymgmt_has: selection = 4
2025-01-16 15:35:27 us=99406 xkey_provider: In keymgmt_has: selection = 2
2025-01-16 15:35:27 us=99421 xkey_provider: In keymgmt_new: entry
2025-01-16 15:35:27 us=99431 xkey_provider: In keydata_new: entry
2025-01-16 15:35:27 us=99442 xkey_provider: In rsa_keymgmt_import: entry
2025-01-16 15:35:27 us=99452 xkey_provider: In keymgmt_import: entry
2025-01-16 15:35:27 us=99463 xkey_provider: In keymgmt_import: importing native key
2025-01-16 15:35:27 us=100154 xkey_provider: In query_operation: op = 10
2025-01-16 15:35:27 us=100210 xkey_provider: In keymgmt_import: imported native RSA key
2025-01-16 15:35:27 us=100223 xkey_provider: In keymgmt_match: entry
2025-01-16 15:35:27 us=100239 xkey_provider: In keymgmt_match: checking key pair match: res = 1
2025-01-16 15:35:27 us=100251 xkey_provider: In keymgmt_match: checking parameter match: res = 1
2025-01-16 15:35:27 us=100265 PKCS#11: pkcs11h_certificate_freeCertificateId entry certificate_id=0x55c06e0a8480
2025-01-16 15:35:27 us=100272 PKCS#11: pkcs11h_token_freeTokenId entry certificate_id=0x55c06e0a88b0
2025-01-16 15:35:27 us=100280 PKCS#11: pkcs11h_token_freeTokenId return
2025-01-16 15:35:27 us=100288 PKCS#11: pkcs11h_certificate_freeCertificateId return
2025-01-16 15:35:27 us=100296 PKCS#11: tls_ctx_use_pkcs11 - return ok=1, rv=0
...

but with tpm2-pkcs11-1.9.1 it fails:

...
2025-01-16 15:48:20 us=47247 OpenVPN 2.6.9 x86_64-pc-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD]
2025-01-16 15:48:20 us=47262 library versions: OpenSSL 3.3.2 3 Sep 2024, LZO 2.10
2025-01-16 15:48:20 us=48280 PKCS#11: pkcs11_initialize - entered
2025-01-16 15:48:20 us=48381 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48402 PKCS#11: pkcs11h_setProperty entry property='1', value=0x7fffa689cf6c, value_size=4
2025-01-16 15:48:20 us=48417 PKCS#11: Setting property 1=0x0
2025-01-16 15:48:20 us=48430 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48443 PKCS#11: pkcs11h_setProperty entry property='7', value=0x7fffa689cf60, value_size=8
2025-01-16 15:48:20 us=48456 PKCS#11: Setting property 7=0x0
2025-01-16 15:48:20 us=48467 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48479 PKCS#11: pkcs11h_setProperty entry property='6', value=0x7fffa689cf68, value_size=8
2025-01-16 15:48:20 us=48491 PKCS#11: Setting property 6=0x558346b43950
2025-01-16 15:48:20 us=48502 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48514 PKCS#11: pkcs11h_setProperty entry property='9', value=0x7fffa689cf60, value_size=8
2025-01-16 15:48:20 us=48542 PKCS#11: Setting property 9=0x55837067e148
2025-01-16 15:48:20 us=48556 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48568 PKCS#11: pkcs11h_setProperty entry property='8', value=0x7fffa689cf68, value_size=8
2025-01-16 15:48:20 us=48580 PKCS#11: Setting property 8=0x558346b437b0
2025-01-16 15:48:20 us=48592 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48604 PKCS#11: pkcs11h_setProperty entry property='10', value=0x7fffa689cf6c, value_size=4
2025-01-16 15:48:20 us=48615 PKCS#11: Setting property 10=0x1
2025-01-16 15:48:20 us=48627 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48638 PKCS#11: pkcs11h_setProperty entry property='11', value=0x7fffa689cf6c, value_size=4
2025-01-16 15:48:20 us=48650 PKCS#11: Setting property 11=0xffffffff
2025-01-16 15:48:20 us=48661 PKCS#11: pkcs11h_setProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48673 PKCS#11: pkcs11_initialize - return 0-'CKR_OK'
2025-01-16 15:48:20 us=48685 PKCS#11: pkcs11_addProvider - entered - provider='/usr/lib64/pkcs11/libtpm2_pkcs11.so', private_mode=00000000
2025-01-16 15:48:20 us=48696 PKCS#11: Adding PKCS#11 provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48708 PKCS#11: pkcs11h_registerProvider entry version='1.29.0', reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48719 PKCS#11: Register provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48732 PKCS#11: pkcs11h_registerProvider Provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48744 PKCS#11: Provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so' registered rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48756 PKCS#11: pkcs11h_registerProvider return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48769 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='0', value=0x55837067dfd8, value_size=36
2025-01-16 15:48:20 us=48781 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:location=/usr/lib64/pkcs11/libtpm2_pkcs11.so
2025-01-16 15:48:20 us=48793 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48805 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='1', value=0x7fffa689cf70, value_size=4
2025-01-16 15:48:20 us=48817 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:allow_protected_auth=0x0
2025-01-16 15:48:20 us=48829 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48841 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='2', value=0x7fffa689cf6c, value_size=4
2025-01-16 15:48:20 us=48853 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:mask_private_mode=0x0
2025-01-16 15:48:20 us=48864 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48876 PKCS#11: pkcs11h_setProviderProperty entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so', property='5', value=0x7fffa689cf74, value_size=4
2025-01-16 15:48:20 us=48888 PKCS#11: Setting provider property /usr/lib64/pkcs11/libtpm2_pkcs11.so:cert_is_private=0x0
2025-01-16 15:48:20 us=48899 PKCS#11: pkcs11h_setProviderProperty return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=48912 PKCS#11: pkcs11h_initializeProvider entry pid=857, reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48924 PKCS#11: Initializing provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=48985 PKCS#11: _pkcs11h_slotevent_notify entry
2025-01-16 15:48:20 us=49000 PKCS#11: _pkcs11h_slotevent_notify return
2025-01-16 15:48:20 us=49012 PKCS#11: pkcs11h_initializeProvider return rv=6-'CKR_FUNCTION_FAILED'
2025-01-16 15:48:20 us=49024 PKCS#11: Cannot initialize provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so' 6-'CKR_FUNCTION_FAILED'
2025-01-16 15:48:20 us=49035 PKCS#11: pkcs11h_removeProvider entry reference='/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=49057 PKCS#11: Removing provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so'
2025-01-16 15:48:20 us=49071 PKCS#11: _pkcs11h_slotevent_notify entry
2025-01-16 15:48:20 us=49082 PKCS#11: _pkcs11h_slotevent_notify return
2025-01-16 15:48:20 us=49094 PKCS#11: pkcs11h_removeProvider return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=49106 PKCS#11: pkcs11_addProvider - return rv=6-'CKR_FUNCTION_FAILED'
2025-01-16 15:48:20 us=49200 NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2025-01-16 15:48:20 us=49220 PO_INIT maxevents=5 flags=0x00000002
2025-01-16 15:48:20 us=49285 xkey_provider: In xkey_provider_init: entry
2025-01-16 15:48:20 us=51204 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51262 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51287 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51297 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51311 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51321 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51338 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51348 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51362 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51372 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51390 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51400 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51413 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51423 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51435 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51445 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51457 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51467 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51479 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51489 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51502 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51512 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51530 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51540 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51552 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51562 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51574 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51584 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51596 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51606 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51620 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51630 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51646 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51656 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51668 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51678 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51690 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51700 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51712 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51722 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51735 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=51745 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=51980 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=51992 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52005 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52036 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52049 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52059 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52073 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52083 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52096 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52106 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52118 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52128 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52140 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52150 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52164 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52174 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52187 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52197 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52210 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52220 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52232 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52242 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52254 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52264 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52276 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52286 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52299 xkey_provider: In query_operation: op = 1
2025-01-16 15:48:20 us=52309 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52416 xkey_provider: In query_operation: op = 12
2025-01-16 15:48:20 us=52465 xkey_provider: In query_operation: op = 11
2025-01-16 15:48:20 us=52476 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52488 xkey_provider: In query_operation: op = 11
2025-01-16 15:48:20 us=52498 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=52510 xkey_provider: In query_operation: op = 12
2025-01-16 15:48:20 us=52735 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52840 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52854 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52870 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52904 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52916 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52932 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52946 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=52961 xkey_provider: In query_operation: op = 10
2025-01-16 15:48:20 us=53083 xkey_provider: In query_operation: op = 5
2025-01-16 15:48:20 us=53094 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=53110 xkey_provider: In query_operation: op = 5
2025-01-16 15:48:20 us=53120 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=53139 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=53149 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=53162 xkey_provider: In query_operation: op = 2
2025-01-16 15:48:20 us=53172 xkey_provider: In query_operation: op not supported
2025-01-16 15:48:20 us=53349 PKCS#11: tls_ctx_use_pkcs11 - entered - ssl_ctx=0x7fffa689da50, pkcs11_id_management=0, pkcs11_id='STMicro//0000000000000000/tpm\x2Dtoken/66346566326638363665336238343537'
2025-01-16 15:48:20 us=53366 PKCS#11: pkcs11h_certificate_deserializeCertificateId entry p_certificate_id=0x7fffa689a9d0, sz='STMicro//0000000000000000/tpm\x2Dtoken/66346566326638363665336238343537'
2025-01-16 15:48:20 us=53376 PKCS#11: _pkcs11h_certificate_newCertificateId entry p_certificate_id=0x7fffa689a988
2025-01-16 15:48:20 us=53397 PKCS#11: _pkcs11h_certificate_newCertificateId return rv=0-'CKR_OK', *p_certificate_id=0x55837070ec70
2025-01-16 15:48:20 us=53407 PKCS#11: pkcs11h_token_deserializeTokenId entry p_token_id=0x55837070ec70, sz='STMicro//0000000000000000/tpm\x2Dtoken'
2025-01-16 15:48:20 us=53416 PKCS#11: _pkcs11h_token_newTokenId entry p_token_id=0x7fffa689a8d8
2025-01-16 15:48:20 us=53425 PKCS#11: _pkcs11h_token_newTokenId return rv=0-'CKR_OK', *p_token_id=0x55837070f0a0
2025-01-16 15:48:20 us=53437 PKCS#11: pkcs11h_token_deserializeTokenId return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=53448 PKCS#11: pkcs11h_certificate_deserializeCertificateId return rv=0-'CKR_OK'
2025-01-16 15:48:20 us=53458 PKCS#11: pkcs11h_certificate_create entry certificate_id=0x55837070ec70, user_data=(nil), mask_prompt=00000007, pin_cache_period=-1, p_certificate=0x7fffa689a9d8
2025-01-16 15:48:20 us=53469 PKCS#11: pkcs11h_certificate_duplicateCertificateId entry to=0x55837070f510 form=0x55837070ec70
2025-01-16 15:48:20 us=53478 PKCS#11: pkcs11h_certificate_duplicateCertificateId return rv=0-'CKR_OK', *to=0x55837070f5a0
2025-01-16 15:48:20 us=53487 PKCS#11: _pkcs11h_session_getSessionByTokenId entry token_id=0x55837070f9d0, p_session=0x55837070f528
2025-01-16 15:48:20 us=53495 PKCS#11: Creating a new session
2025-01-16 15:48:20 us=53505 PKCS#11: pkcs11h_token_duplicateTokenId entry to=0x55837070fe78 form=0x55837070f9d0
2025-01-16 15:48:20 us=53513 PKCS#11: pkcs11h_token_duplicateTokenId return rv=0-'CKR_OK', *to=0x558370710160
2025-01-16 15:48:20 us=53522 PKCS#11: _pkcs11h_session_getSessionByTokenId return rv=0-'CKR_OK', *p_session=0x55837070fe60
2025-01-16 15:48:20 us=53530 PKCS#11: pkcs11h_certificate_create return rv=0-'CKR_OK' *p_certificate=0x55837070f510
2025-01-16 15:48:20 us=53539 PKCS#11: pkcs11h_openssl_getX509 - entry certificate=0x55837070f510
2025-01-16 15:48:20 us=53573 PKCS#11: pkcs11h_certificate_getCertificateBlob entry certificate=0x55837070f510, certificate_blob=(nil), *p_certificate_blob_size=0000000000000000
2025-01-16 15:48:20 us=53582 PKCS#11: __pkcs11h_certificate_loadCertificate entry certificate=0x55837070f510
2025-01-16 15:48:20 us=53590 PKCS#11: _pkcs11h_session_validate entry session=0x55837070fe60
2025-01-16 15:48:20 us=53599 PKCS#11: _pkcs11h_session_validate return rv=179-'CKR_SESSION_HANDLE_INVALID'
2025-01-16 15:48:20 us=53607 PKCS#11: __pkcs11h_certificate_loadCertificate return rv=179-'CKR_SESSION_HANDLE_INVALID'
2025-01-16 15:48:20 us=53615 PKCS#11: _pkcs11h_certificate_resetSession entry certificate=0x55837070f510, public_only=1, session_mutex_locked=0
2025-01-16 15:48:20 us=53624 PKCS#11: _pkcs11h_session_login entry session=0x55837070fe60, is_publicOnly=1, readonly=1, user_data=(nil), mask_prompt=00000007
2025-01-16 15:48:20 us=53632 PKCS#11: _pkcs11h_session_logout entry session=0x55837070fe60
2025-01-16 15:48:20 us=53640 PKCS#11: _pkcs11h_session_logout return
2025-01-16 15:48:20 us=53649 PKCS#11: _pkcs11h_session_reset entry session=0x55837070fe60, user_data=(nil), mask_prompt=00000007, p_slot=0x7fffa689a7c0
2025-01-16 15:48:20 us=53657 PKCS#11: _pkcs11h_session_reset Expected token manufacturerID='STMicro' model='', serialNumber='0000000000000000', label='tpm-token'
2025-01-16 15:48:20 us=53666 PKCS#11: _pkcs11h_session_getSlotList entry provider=0x5583706cb740, token_present=1, pSlotList=0x7fffa689a688, pulCount=0x7fffa689a690
2025-01-16 15:48:20 us=53675 PKCS#11: _pkcs11h_session_getSlotList return rv=400-'CKR_CRYPTOKI_NOT_INITIALIZED' *pulCount=0
2025-01-16 15:48:20 us=53684 PKCS#11: Cannot get slot list for provider 'r/lib64/pkcs11/libtpm2_pkcs11.so' rv=400-'CKR_CRYPTOKI_NOT_INITIALIZED'
2025-01-16 15:48:20 us=53692 PKCS#11: Calling token_prompt hook for 'tpm-token'
2025-01-16 15:48:20 us=53722 neither stdin nor stderr are a tty device and you have neither a controlling tty nor systemd - can't ask for 'NEED-OK|token-insertion-request|Please insert tpm-token token:'.  If you used --daemon, you need to use --askpass to make passphrase-protected keys work, and you can not use --auth-nocache.
2025-01-16 15:48:20 us=53745 Exiting due to fatal error

At token-insertion-request it goes to infinity loop on 'ok' input and bails out to error on any other input.

But seems, that the problem occurs earlier, at Initializing provider '/usr/lib64/pkcs11/libtpm2_pkcs11.so' which returns CKR_FUNCTION_FAILED instead of CKR_OK