engine-pkcs11-0.1.4 fails in get_pin

[agriffis]

I'm using Debian Lenny with a Rainbow iKey 3000. Here are the package versions:

$ dpkg -l libengine-pkcs11-openssl libopenct1 openct opensc openssl pcscd stunnel4 | cat
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Installed/Config-files/Unpacked/Failed-config/Half-installed
|/ Err?=(none)/Hold/Reinst-required/X=both-problems (Status,Err: uppercase=bad)
||/ Name                     Version        Description
+++-========================-==============-============================================
ii  libengine-pkcs11-openssl 0.1.4-1        OpenSSL engine for PKCS#11 modules
ii  libopenct1               0.6.12-1       middleware framework for smart card terminal
ii  openct                   0.6.12-1       middleware framework for smart card terminal
ii  opensc                   0.11.3-1       SmartCard utilities with support for PKCS#15
ii  openssl                  0.9.8e-6       Secure Socket Layer (SSL) binary and related
ii  pcscd                    1.4.4-1        Middleware to access a smart card using PC/S
ii  stunnel4                 3:4.20-2       Universal SSL tunnel for network daemons

and here is my stunnel configuration:

debug = debug
foreground = yes

pid = /home/agriffis/stunnel4.pid
client = yes
engine = dynamic
engineCtrl = SO_PATH:/usr/lib/engines/engine_pkcs11.so
engineCtrl = ID:pkcs11
engineCtrl = LIST_ADD:1
engineCtrl = LOAD
engineCtrl = MODULE_PATH:/usr/lib/opensc-pkcs11.so
engineCtrl = INIT

[http]
client = yes
cert = /tmp/hardware.crt
key = [snipped]
engineNum = 1
accept = localhost:7070
connect = [snipped]

This configuration works with engine-pkcs11-0.1.3 but fails with 0.1.4. The problem occurs in get_pin due to this snippet which is new in 0.1.4:

static char *get_pin(UI_METHOD * ui_method, void *callback_data, char *sc_pin,
                     int maxlen)
{
        UI *ui;
        struct {
                const void *password;
                const char *prompt_info;
        } *mycb = callback_data;

        if (mycb->password) {
                sc_pin = set_pin(mycb->password);
                return sc_pin;
        }

If I comment out the mycb->password test then I'm prompted on the terminal, as it worked in 0.1.3. With the code as it stands, the prompt never appears:

2007.09.08 11:38:29 LOG7[21430:3082663600]: Enabling support for engine 'dynamic'
2007.09.08 11:38:29 LOG7[21430:3082663600]: Executing engine control command SO_PATH:/usr/lib/engines/engine_pkcs11.so
2007.09.08 11:38:29 LOG7[21430:3082663600]: Executing engine control command ID:pkcs11
2007.09.08 11:38:29 LOG7[21430:3082663600]: Executing engine control command LIST_ADD:1
2007.09.08 11:38:29 LOG7[21430:3082663600]: Executing engine control command LOAD
2007.09.08 11:38:29 LOG7[21430:3082663600]: Executing engine control command MODULE_PATH:/usr/lib/opensc-pkcs11.so
2007.09.08 11:38:29 LOG7[21430:3082663600]: Initializing engine 1
[opensc-pkcs11] iso7816.c:99:iso7816_check_sw: File not found
[opensc-pkcs11] card-starcos.c:312:starcos_select_fid: returning with: File not found
[opensc-pkcs11] card.c:554:sc_select_file: returning with: File not found
[opensc-pkcs11] pkcs15-pubkey.c:402:sc_pkcs15_read_pubkey: Failed to read public key file.
2007.09.08 11:38:41 LOG7[21430:3082663600]: Engine 1 initialized
2007.09.08 11:38:41 LOG6[21430:3082663600]: Unable to retrieve any random data from /home/agriffis/.rnd
2007.09.08 11:38:41 LOG7[21430:3082663600]: Wrote 0 new random bytes to /home/agriffis/.rnd
2007.09.08 11:38:41 LOG7[21430:3082663600]: RAND_status claims sufficient entropy for the PRNG
2007.09.08 11:38:41 LOG7[21430:3082663600]: PRNG seeded successfully
2007.09.08 11:38:41 LOG7[21430:3082663600]: Certificate: /tmp/hardware.crt
2007.09.08 11:38:41 LOG7[21430:3082663600]: Certificate loaded
2007.09.08 11:38:41 LOG7[21430:3082663600]: Key file: [snipped]
[opensc-pkcs11] sec.c:201:sc_pin_cmd: returning with: PIN code or key incorrect
Login failed
PKCS11_get_private_key returned NULL
2007.09.08 11:38:41 LOG3[21430:3082663600]: error stack: 26096080 : error:26096080:engine routines:ENGINE_load_private_key:failed loa
ding private key
2007.09.08 11:38:41 LOG3[21430:3082663600]: error stack: 800050A0 : error:800050A0:Vendor defined:PKCS11_login:PIN incorrect
2007.09.08 11:38:41 LOG3[21430:3082663600]: Wrong PIN: retrying
[opensc-pkcs11] sec.c:201:sc_pin_cmd: returning with: PIN code or key incorrect
Login failed
PKCS11_get_private_key returned NULL
2007.09.08 11:38:41 LOG3[21430:3082663600]: error stack: 26096080 : error:26096080:engine routines:ENGINE_load_private_key:failed loa
ding private key
2007.09.08 11:38:41 LOG3[21430:3082663600]: error stack: 800050A0 : error:800050A0:Vendor defined:PKCS11_login:PIN incorrect
2007.09.08 11:38:41 LOG3[21430:3082663600]: Wrong PIN: retrying
[opensc-pkcs11] sec.c:201:sc_pin_cmd: returning with: PIN code or key incorrect
Login failed
PKCS11_get_private_key returned NULL
2007.09.08 11:38:42 LOG3[21430:3082663600]: error stack: 26096080 : error:26096080:engine routines:ENGINE_load_private_key:failed loa
ding private key
2007.09.08 11:38:42 LOG3[21430:3082663600]: ENGINE_load_private_key: 800050A0: error:800050A0:Vendor defined:PKCS11_login:PIN incorre
ct

Please let me know if there's anything more I can do to help debug this problem. It's gradually breaking our users' systems as they get the 0.1.4 update in the various distributions.

[rsnel]

I have the same problem. I read the sourcecode and noticed the following.

The pointer passed by stunnel as callback_data points to this struct (see: stunnel4-4.22/src/prototypes.h):

typedef struct {
    LOCAL_OPTIONS *section;
    char pass[PEM_BUFSIZE];
} UI_DATA;

But get_pin() assumes callback_data to point to

struct {
        const void *password;
        const char *prompt_info;
} *mycb = callback_data;

Since callback_data is opaque (it is passed by stunnel as private data for the ui functions), get_pin has IMO no business whatshowever to make assumptions about what it points to and should not touch it.

The proper fix is to remove this code and solve the problem which it solved in the caller.

I raise the severity to major, since this bug (in conjunction with a nice for() loop in stunnel4 to retry the wrong PIN three times in a row) rendered my usb token unusable for the weekend and requires me to bother the IT guys at work to unblock it.

The bug still exists in trunk/ so I upped the version to trunk.

[crash]

The same problem here, my application does need a special UI which uses no callback data, so it calls ENGINE_load_private_key with callback data set to NULL. The problem is that the engine does not check whether the callback_data pointer is NULL or not and tries to access it's pin element which of course generates a segmentation fault. I'll attach a very simple patch to solve this issue.

[crash]

patch to fix illegal access to callback_data elements if callback data is NULL

[ludovic]

Fixed in revision r110

[agriffis]

The patch provided may fix the segfault that "crash" reports, but it doesn't fix the original problem in this report. Re-opening.

[javier]

I'm using 0.1.8 version and I'm still getting the problem of not getting prompted for the pin.

I'm reverting to 0.1.3...

Could it be that others are experiencing this as well? I noticed the bug was re-open a year and 2 months ago, however there's no movement ever since...