C_Initialize() calls itself in a loop when pkcs-spy is used with SoftHSM from Homebrew (on macOS)

[LudovicRousseau]

Problem Description

I try to use pkcs11-spy on macOS Ventura 13.6 (22G120).
My problem is that C_Initialize() from pkcs-spy calls itself recursively until the stack is full and the application crashes.
Instead C_Initialize() from pkcs-spy should call C_Initialize() from the PKCS#11 lib I configured in PKCS11SPY.

I tried with the current git version of OpenSC.

PKCS11SPY=/usr/local/lib/softhsm/libsofthsm2.so pkcs11-tool -I --module=/usr/local/lib/pkcs11-spy.so


*************** OpenSC PKCS#11 spy *****************
Loaded: "/usr/local/lib/softhsm/libsofthsm2.so"

0: C_GetInterface
P:49666; T:0x140704475666176 2023-09-22 23:20:36.564
[compat]
[in] pInterfaceName 000000010a03bb6c / 7
    00000000  50 4B 43 53 20 31 31                             PKCS 11         
[in] pVersion = NULL
[in] flags = 
Returned:  0 CKR_OK

1: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:36.564
[in] pInitArgs = 0x0

2: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:36.564
[in] pInitArgs = 0x0

3: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:36.565
[in] pInitArgs = 0x0

4: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:36.565
[in] pInitArgs = 0x0

[...]

174597: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:37.798
[in] pInitArgs = 0x0

174598: C_Initialize
P:49666; T:0x140704475666176 2023-09-22 23:20:37.798
[in] pInitArgs = 0x0
Segmentation fault: 11

Proposed Resolution

I have no solution.
I am pretty sure I already got this problem a few years back. But I do not remember how I solved it.

It looks like a symbol resolution issue between C_Initialize() from pkcs-spy and C_Initialize() from the PKCS#11 library I want to spy.

I guess the issue is specific to macOS.

Steps to reproduce

PKCS11SPY=/usr/local/lib/softhsm/libsofthsm2.so pkcs11-tool -I --module=/usr/local/lib/pkcs11-spy.so

Logs

It is not a problem with OpenSC itself.

[frankmorgner]

What version are you using?

[frankmorgner]

I can't reproduce this on Linux with master

[Jakuje]

I never saw this issue on Linux either so I assume it will be something osx (or osx build) specific.

[LudovicRousseau]

I was using the git version as of 2 days ago.
Yes, I have no problem on GNU/Linux, only macOS.

I tried again with OpenSC lib (and also another PKCS#11 lib) instead of SoftHSM and it works fine.

$ PKCS11SPY=/usr/local/lib/pkcs11/opensc-pkcs11.so pkcs11-tool -I --module=/usr/local/lib/pkcs11-spy.so


*************** OpenSC PKCS#11 spy *****************
Loaded: "/usr/local/lib/pkcs11/opensc-pkcs11.so"

0: C_GetInterface
P:39981; T:0x8354979968 2023-09-25 10:45:56.843
[in] pInterfaceName 00000001044e3a8e / 7
    00000000  50 4B 43 53 20 31 31                             PKCS 11         
[in] pVersion = NULL
[in] flags = 
Returned:  0 CKR_OK

1: C_Initialize
P:39981; T:0x8354979968 2023-09-25 10:45:56.844
[in] pInitArgs = 0x0
Returned:  0 CKR_OK

2: C_GetInfo
P:39981; T:0x8354979968 2023-09-25 10:45:56.865
[out] pInfo: 
      cryptokiVersion:         3.0
      manufacturerID:         'OpenSC Project                  '
      flags:                   0
      libraryDescription:     'OpenSC smartcard framework      '
      libraryVersion:          0.23
Returned:  0 CKR_OK
Cryptoki version 3.0
Manufacturer     OpenSC Project
Library          OpenSC smartcard framework (ver 0.23)

3: C_GetSlotList
P:39981; T:0x8354979968 2023-09-25 10:45:56.865
[in] tokenPresent = 0x0
[out] pSlotList: 
Count is 0
[out] *pulCount = 0x0
Returned:  0 CKR_OK
No slots.

4: C_Finalize
P:39981; T:0x8354979968 2023-09-25 10:45:56.865
Returned:  0 CKR_OK

Maybe the problem is specific to SofHSM on macOS?
I will have a look.

[Jakuje]

Could it be if there is something loading softhsm from OpenSSL initialization, for example as a engine/provider?

We had some fixes to prevent doing the same from the pkcs11-provider in OpenSC (#2712). Its possible that SoftHSM might need something similar.

[LudovicRousseau]

If I rebuild SoftHSM I do not have the problem any more :-(

I now have a working configuration.
But I have no idea why I have this behaviour with SoftHSM from Homebrew.

You can ignore this bug. No need to invest time on it.
Maybe we can keep the ticket open for the next time I have the problem?

[frankmorgner]

On macOS, I built softhsm from its git repository and could not reproduce this either.

[frankmorgner]

Please open a new ticket, if you have new debug information, thank you.