Comments (10)
qpernil
commented on July 29, 2024
Would you kindly provide the versions of the yubihsm_pkcs11 module, the libpkcs11 engine and openssl ? The OS version would also be helpful. Thank you.
As a side I can comment that the password needs to start with 4 hex digits, but maybe this was just an example.
It was previously a known error that the pkcs11 module (actually the underlying library) would leak sessions if authentication failed, by not closing them. The yubihhsm itself has a timeout for sessions, that is why it works again if you wait.
But if the password was correct this is not the issue here. Also, if the version is current it should not be the issue even with and incorrect password.
from yubihsm-shell.
ktrinh-anduril
commented on July 29, 2024
Thanks for the quick replies! Here are the version info:
- libp11(pkcs11 engine): 0.4.12
- yubihsm: 2.4.2
- openssl: 1.1.1
We are currently running NixOS 23.05
Yeah for the password, it's definitely 4 numbers, I just didn't type it in correctly
from yubihsm-shell.
qpernil
commented on July 29, 2024
Also,could you set the YUBIHSM_PKCS11_DINOUT and YUBIHSM_PKCS11_DBG env variables and re-run the command, and then show the end parts of the log, so we can see if C_CloseSession (or possibly C_CloseAllSessions) is called. If it isn't then there is something wrong outside yubihsm_pkcs11.
from yubihsm-shell.
ktrinh-anduril
commented on July 29, 2024
This is the log, I don't see the C_CloseSession which makes sense why things are not closing.
stage4> engine "pkcs11" set.
stage4> [P11 - INF 22:45:16.770429] yubihsm_pkcs11.c:446 (C_GetFunctionList): In
stage4> [P11 - INF 22:45:16.770533] yubihsm_pkcs11.c:455 (C_GetFunctionList): Out
stage4> [P11 - INF 22:45:16.770547] yubihsm_pkcs11.c:107 (C_Initialize): In
stage4> [P11 - INF 22:45:16.770586] yubihsm_pkcs11.c:213 (C_Initialize): Now parsing supplied init args as '--connector=http://127.0.0.1:12345 --debug '
stage4> [P11 - INF 22:45:16.770620] yubihsm_pkcs11.c:257 (C_Initialize): Found 1 configured connector(s)
stage4> [P11 - INF 22:45:16.781030] yubihsm_pkcs11.c:336 (C_Initialize): Found 1 usable connector(s)
stage4> [P11 - INF 22:45:16.781054] yubihsm_pkcs11.c:338 (C_Initialize): Found 0 configured device public key(s)
stage4> [P11 - INF 22:45:16.781065] yubihsm_pkcs11.c:343 (C_Initialize): Out
stage4> [P11 - INF 22:45:16.781077] yubihsm_pkcs11.c:412 (C_GetInfo): In
stage4> [P11 - INF 22:45:16.781089] yubihsm_pkcs11.c:438 (C_GetInfo): Out
stage4> [P11 - INF 22:45:16.781103] yubihsm_pkcs11.c:464 (C_GetSlotList): In
stage4> [P11 - INF 22:45:16.781112] yubihsm_pkcs11.c:493 (C_GetSlotList): Total number of slots is 1
stage4> [P11 - INF 22:45:16.781122] yubihsm_pkcs11.c:496 (C_GetSlotList): Can return 1 slot(s)
stage4> [P11 - INF 22:45:16.781130] yubihsm_pkcs11.c:500 (C_GetSlotList): Out
stage4> [P11 - INF 22:45:16.781140] yubihsm_pkcs11.c:464 (C_GetSlotList): In
stage4> [P11 - INF 22:45:16.781149] yubihsm_pkcs11.c:521 (C_GetSlotList): Returning slot 0
stage4> [P11 - INF 22:45:16.781159] yubihsm_pkcs11.c:538 (C_GetSlotList): Out
stage4> [P11 - INF 22:45:16.781170] yubihsm_pkcs11.c:545 (C_GetSlotInfo): In
stage4> [P11 - INF 22:45:16.781181] yubihsm_pkcs11.c:596 (C_GetSlotInfo): Out
stage4> [P11 - INF 22:45:16.781193] yubihsm_pkcs11.c:603 (C_GetTokenInfo): In
stage4> [P11 - INF 22:45:16.782637] yubihsm_pkcs11.c:694 (C_GetTokenInfo): Out
stage4> [P11 - INF 22:45:16.782661] yubihsm_pkcs11.c:841 (C_OpenSession): In
stage4> [P11 - INF 22:45:16.782690] yubihsm_pkcs11.c:886 (C_OpenSession): Allocated session 1
stage4> [P11 - INF 22:45:16.782701] yubihsm_pkcs11.c:888 (C_OpenSession): Out
stage4> [P11 - INF 22:45:16.782818] yubihsm_pkcs11.c:1945 (C_FindObjectsInit): In
stage4> [P11 - INF 22:45:16.782834] yubihsm_pkcs11.c:1982 (C_FindObjectsInit): Out
stage4> [P11 - INF 22:45:16.782844] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.782854] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.782864] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 0 object(s)
stage4> [P11 - INF 22:45:16.782874] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.782886] yubihsm_pkcs11.c:2344 (C_FindObjectsFinal): In
stage4> [P11 - INF 22:45:16.782896] yubihsm_pkcs11.c:2368 (C_FindObjectsFinal): Out
stage4> [P11 - INF 22:45:16.782909] yubihsm_pkcs11.c:1110 (C_Login): In
stage4> [P11 - INF 22:45:16.804887] yubihsm_pkcs11.c:1233 (C_Login): Out
stage4> [P11 - INF 22:45:16.804929] yubihsm_pkcs11.c:1945 (C_FindObjectsInit): In
stage4> [P11 - INF 22:45:16.804955] yubihsm_pkcs11.c:1998 (C_FindObjectsInit): find with 1 attributes
stage4> [P11 - INF 22:45:16.810446] yubihsm_pkcs11.c:2243 (C_FindObjectsInit): Out
stage4> [P11 - INF 22:45:16.810464] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.810477] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.810491] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 0 as 03030012
stage4> [P11 - INF 22:45:16.810503] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.810516] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.810529] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.810541] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816278] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.816310] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.816324] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.816337] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816348] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816356] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816367] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.816378] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.816390] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.816403] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816416] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816428] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816440] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.816453] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.816465] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.816476] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816488] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816499] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816508] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.816518] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.816531] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.816544] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816554] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816563] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816573] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.816585] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.816598] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.816611] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816622] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816631] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 03030012
stage4> [P11 - INF 22:45:16.816640] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.816653] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.816665] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.816679] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.816693] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.816704] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.816716] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 1 as 00030013
stage4> [P11 - INF 22:45:16.816730] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.816741] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.816752] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.816761] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.822914] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.822945] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.822963] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.822985] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823023] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823039] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.823055] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.823073] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.823089] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.823104] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823118] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823129] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.823140] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.823153] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.823164] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.823171] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823181] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823193] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.823206] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.823217] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.823225] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.823237] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823249] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823259] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.823267] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.823280] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.823292] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.823305] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823316] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823324] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030013
stage4> [P11 - INF 22:45:16.823334] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.823347] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.823356] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.823366] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.823377] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.823388] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.823401] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 2 as 01030014
stage4> [P11 - INF 22:45:16.823413] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.823425] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.823436] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.823447] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829281] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.829310] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.829322] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.829334] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829346] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829358] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829368] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.829377] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.829389] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.829402] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829415] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829423] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829435] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.829447] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.829457] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.829465] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829478] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829487] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829496] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.829504] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.829513] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.829523] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829532] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829540] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829551] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.829563] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.829576] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.829588] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829599] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829612] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030014
stage4> [P11 - INF 22:45:16.829622] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.829631] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.829641] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.829652] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.829663] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.829673] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.829682] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 3 as 00030015
stage4> [P11 - INF 22:45:16.829695] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.829707] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.829719] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.829728] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.835670] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.835688] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.835699] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.835711] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.835725] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.835736] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.835744] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.835754] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.835766] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.835779] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.835790] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.835799] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.835810] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.835820] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.835829] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.835841] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.835852] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.835864] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.835875] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.835886] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.835899] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.835912] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.835923] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.835934] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.835947] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.835958] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.835967] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.835976] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.835986] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.835996] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030015
stage4> [P11 - INF 22:45:16.836005] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.836014] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.836024] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.836035] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.836044] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.836054] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.836063] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 4 as 00030016
stage4> [P11 - INF 22:45:16.836071] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.836083] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.836095] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.836107] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842146] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.842174] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.842196] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.842215] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842235] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842256] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842279] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.842305] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.842317] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.842329] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842341] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842352] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842363] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.842373] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.842384] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.842396] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842410] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842420] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842432] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.842442] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.842453] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.842468] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842477] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842487] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842498] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.842510] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.842522] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.842534] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842546] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842557] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030016
stage4> [P11 - INF 22:45:16.842568] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.842580] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.842592] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.842604] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.842617] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.842629] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.842641] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 5 as 01030020
stage4> [P11 - INF 22:45:16.842653] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.842666] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.842682] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.842693] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.848834] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.848863] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.848882] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.848903] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.848920] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.848930] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.848946] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.848955] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.848965] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.848976] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.848987] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.848997] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.849009] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.849021] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.849034] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.849043] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.849053] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.849063] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.849078] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.849089] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.849098] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.849110] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.849121] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.849132] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.849141] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.849149] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.849158] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.849168] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.849179] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.849192] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.849203] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.849215] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.849224] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.849234] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.849244] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.849253] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.849263] yubihsm_pkcs11.c:2327 (C_FindObjects): Returning object 6 as 00030021
stage4> [P11 - INF 22:45:16.849271] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 1 object(s)
stage4> [P11 - INF 22:45:16.849283] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.849294] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.849303] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855128] util_pkcs11.c:4026 (populate_template): Getting attribute 0x0
stage4> [P11 - INF 22:45:16.855144] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.855154] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.855167] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855181] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855190] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855198] util_pkcs11.c:4026 (populate_template): Getting attribute 0x100
stage4> [P11 - INF 22:45:16.855211] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 8
stage4> [P11 - INF 22:45:16.855222] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 8
stage4> [P11 - INF 22:45:16.855232] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855242] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855254] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855267] util_pkcs11.c:4026 (populate_template): Getting attribute 0x102
stage4> [P11 - INF 22:45:16.855276] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 2
stage4> [P11 - INF 22:45:16.855288] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 2
stage4> [P11 - INF 22:45:16.855299] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855312] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855323] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855335] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.855347] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 40
stage4> [P11 - INF 22:45:16.855360] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.855371] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855379] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855390] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855401] util_pkcs11.c:4026 (populate_template): Getting attribute 0x3
stage4> [P11 - INF 22:45:16.855411] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 40
stage4> [P11 - INF 22:45:16.855420] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 40
stage4> [P11 - INF 22:45:16.855431] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855443] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855454] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 00030021
stage4> [P11 - INF 22:45:16.855463] util_pkcs11.c:4026 (populate_template): Getting attribute 0x202
stage4> [P11 - INF 22:45:16.855473] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 1
stage4> [P11 - INF 22:45:16.855483] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 1
stage4> [P11 - INF 22:45:16.855494] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.855504] yubihsm_pkcs11.c:2261 (C_FindObjects): In
stage4> [P11 - INF 22:45:16.855516] yubihsm_pkcs11.c:2285 (C_FindObjects): Can return 1 object(s)
stage4> [P11 - INF 22:45:16.855529] yubihsm_pkcs11.c:2331 (C_FindObjects): Returning 0 object(s)
stage4> [P11 - INF 22:45:16.855540] yubihsm_pkcs11.c:2333 (C_FindObjects): Out
stage4> [P11 - INF 22:45:16.855552] yubihsm_pkcs11.c:2344 (C_FindObjectsFinal): In
stage4> [P11 - INF 22:45:16.855563] yubihsm_pkcs11.c:2368 (C_FindObjectsFinal): Out
stage4> [P11 - INF 22:45:16.855578] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.855588] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.855597] util_pkcs11.c:4026 (populate_template): Getting attribute 0x120
stage4> [P11 - INF 22:45:16.871860] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 512
stage4> [P11 - INF 22:45:16.871889] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 512
stage4> [P11 - INF 22:45:16.871908] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.871921] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.871932] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.871943] util_pkcs11.c:4026 (populate_template): Getting attribute 0x120
stage4> [P11 - INF 22:45:16.888154] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 512
stage4> [P11 - INF 22:45:16.888169] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 512
stage4> [P11 - INF 22:45:16.888179] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.888195] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.888205] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.888215] util_pkcs11.c:4026 (populate_template): Getting attribute 0x122
stage4> [P11 - INF 22:45:16.888226] util_pkcs11.c:4042 (populate_template): Retrieving only length which is 3
stage4> [P11 - INF 22:45:16.888235] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 3
stage4> [P11 - INF 22:45:16.888244] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.888256] yubihsm_pkcs11.c:1779 (C_GetAttributeValue): In
stage4> [P11 - INF 22:45:16.888268] yubihsm_pkcs11.c:1797 (C_GetAttributeValue): For object 01030020
stage4> [P11 - INF 22:45:16.888277] util_pkcs11.c:4026 (populate_template): Getting attribute 0x122
stage4> [P11 - INF 22:45:16.888286] util_pkcs11.c:4049 (populate_template): Retrieving attribute value, length is 3
stage4> [P11 - INF 22:45:16.888298] util_pkcs11.c:4069 (populate_template): Attribute/length successfully returned with length 3
stage4> [P11 - INF 22:45:16.888307] yubihsm_pkcs11.c:1841 (C_GetAttributeValue): Out
stage4> [P11 - INF 22:45:16.888459] yubihsm_pkcs11.c:3480 (C_SignInit): In
stage4> [P11 - INF 22:45:16.888473] yubihsm_pkcs11.c:3505 (C_SignInit): Trying to sign data with mechanism 0x0001 and key 01030020
stage4> [P11 - INF 22:45:16.889688] yubihsm_pkcs11.c:3548 (C_SignInit): RSA signature requested
stage4> [P11 - INF 22:45:16.889703] yubihsm_pkcs11.c:3640 (C_SignInit): Out
stage4> [P11 - INF 22:45:16.889713] yubihsm_pkcs11.c:3653 (C_Sign): In
stage4> [P11 - INF 22:45:16.889724] yubihsm_pkcs11.c:3678 (C_Sign): The size of the signature will be 512
stage4> [P11 - INF 22:45:16.889734] yubihsm_pkcs11.c:3701 (C_Sign): Sending 48 bytes to sign
stage4> [P11 - INF 22:45:16.889742] yubihsm_pkcs11.c:3715 (C_Sign): Using key 0020
stage4> [P11 - INF 22:45:16.889752] yubihsm_pkcs11.c:3716 (C_Sign): After padding and transformation there are 48 bytes
stage4> [P11 - INF 22:45:17.757315] yubihsm_pkcs11.c:3726 (C_Sign): Got 512 bytes back
stage4> [P11 - INF 22:45:17.757337] yubihsm_pkcs11.c:3728 (C_Sign): Out
from yubihsm-shell.
qpernil
commented on July 29, 2024
So it would seem yubihsm_pkcs11 is not getting deinitialized in any way, and hence cannot know that it should close the session(s). This will leave a session open in the yubihsm, which will then after 15 seconds time out.
from yubihsm-shell.
ktrinh-anduril
commented on July 29, 2024
Gotcha, any special config needed to deinitialize it? I have been following the tutorial from the yubihsm site here: https://developers.yubico.com/YubiHSM2/Usage_Guides/OpenSSL_with_pkcs11_engine.html and I didn't see mention of special cleanup
from yubihsm-shell.
ktrinh-anduril
commented on July 29, 2024
Okay I think I understand why things are not playing well with each other. So libp11 will wait for a new session forever as specified here by checking for if the C_OpenSession call returns CKR_SESSION_COUNT, however, it looks like on the yubihsm, C_OpenSession doesn't actually reserve a session with the physical yubikey so this always succeed. After that success though, libp11 will call C_Login which will trigger yubihsm to actually reserve a session with a physical device and return the too many session error, however, by this point, libp11 already exits its wait loop for available session so it just errors out
I think a possible fix would be for yubihsm to actually reserve the session with the physical yubikey itself in C_OpenSession so that if we don't have enought session, libp11 knows to wait
from yubihsm-shell.
qpernil
commented on July 29, 2024
C_OpenSession doesn't open a physical session because with the yubihsm a session is always encrypted, so we can't open one until we have a password. Secondly, since login state is global (per process) in pkcs#11 there is no need for a separate physical session per logical (pkcs#11) session. In fact it would make things complicated, as per the pkcs#11 standard all (pkcs#11) sessions transition between logged in and not logged in (and a third SO state) simultaneously. We have no set upper limit on pkcs#11 sessions that can be opened as they only represent some memory which is dynamically allocated. (A pkcs#11 session does however represent a RO or RW state, which we keep track of in the library)
Having said all that I don't think this has any bearing on the fundamental problem, which is that as the openssl command / process dies it does not tell yubihsm_pkcs11 to clean up (either openssl doesn't tell the libp11 engine or the libp11 engine doesn't tell yubihsm_pkcs11), and thus we leave a session open on the yubihsm device. As that process dies it forgets the session keys and hence the session is now useless, but the yubihsm device can't know that. And we can't clean the session up in a new instance of yubihsm_pkcs11 since we can't know if there is a client still using it.
I would say the next step might be to try to debug the libp11 engine and see if it gets a cleanup, and what it does with it.
from yubihsm-shell.
ktrinh-anduril
commented on July 29, 2024
okay I went down the blackhole and it looks like there is a reference counting bug in openssl that's why clean up wasn't called. Fixing that bug results in another deadlocking bug though so I think for now I will just use our delay workaround
from yubihsm-shell.
qpernil
commented on July 29, 2024
Maybe this could be useful https://github.com/latchset/pkcs11-provider
from yubihsm-shell.
Related Issues (20)
- Unwrapping an exported wrapped key without device involvement HOT 4
- Remote problem HOT 1
- the last changelog entry references wrong version HOT 1
- RFE: is it possible to start making github releases?🤔
- Changelog typo HOT 1
- Unable to import an asymmetric wrapping key? HOT 6
- Cannot generate RSA-OAEP key pair? HOT 3
- Error running keytool on windows with YubiHSM HOT 11
- AES CTR Encryption HOT 3
- Failed to store symmetric key: Invalid command HOT 4
- yubihsm-shell ignores env var YUBIHSM_PKCS11_CONF HOT 2
- "debug" option in config file explodes the shell HOT 5
- Malformed data error when signing SHA3-384 with yh_util_sign_pkcs1v1_5 HOT 1
- 2.4.2: test suite fails in 12% units HOT 7
- Docker container cannot connect to yubihsm connector running on host on Ubuntu 22.04.3 LTS HOT 1
- Inquiry about YubiHSM 2 Authentication & Access control HOT 1
- Support for SHA3-* HOT 1
- [P11 - ERR 21:10:53.246143] util_pkcs11.c:4593 (parse_rsa_generate_template): Boolean truth check failed for attribute 0x1 [P11 - ERR 21:10:53.246154] yubihsm_pkcs11.c:5248 (C_GenerateKeyPair): Unable to parse generation template HOT 5
- Can't build on Windows
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from yubihsm-shell.