pkcs11-tool --init core dumps or fails to work second time

[bnevis-i]

Environment

Board: APL UPSquared with PTT
OS: Ubuntu 20.04 (opensc 0.20.0-3)
tpm2-tss: 4.2.1 (tarball)
tpm2-pkcs11: 1.3.1 (tarball)
tpm2-tools: Not installed
tpm2-abrmd: Not installed

Error message

pkcs11-tool --module /usr/lib/libtpm2_pkcs11.so --init-token --label tpmhsm --so-pin (redacted) --pin (redacted)
Using slot 0 with a present token (0x1)
Token successfully initialized
Segmentation fault (core dumped)

pkcs11-tool --module /usr/lib/libtpm2_pkcs11.so --init-token --label tpmhsm --so-pin (redacted) --pin (redacted)
Using slot 0 with a present token (0x1)
ERROR: step error: UNIQUE constraint failed: tokens.id
ERROR: Could not add token to db
error: PKCS11 function C_InitToken failed: rv = CKR_GENERAL_ERROR (0x5)
Aborting.

[williamcroberts]

The return seems fine, I have set up so you cannot have N tokens with the same name in a TPM2_PKCS11_STORE. I think the abort is in pkcs11-tool.

Maybe run it valgrind or a debugger to see where it hits the abort call? I cannot reproduce.

[bnevis-i]

Debugger output:

Using slot 0 with a present token (0x1)
Token successfully initialized

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff731e94e in twist_len (tstring=0x0) at src/lib/twist.c:157
157		size_t len = str->end - str->data;
(gdb) bt
#0  0x00007ffff731e94e in twist_len (tstring=0x0) at src/lib/twist.c:157
#1  0x00007ffff73176a5 in tpm_loadobj (ctx=0x5555555aabe0, phandle=4293479, auth=0x0, pub_data=0x0, priv_data=0x0, 
    handle=0x5555555aebc8) at src/lib/tpm.c:793
#2  0x00007ffff73106aa in session_ctx_login (ctx=0x5555555ad590, user=1, pin=0x7fffffffe39b "123456", pinlen=6)
    at src/lib/session_ctx.c:285
#3  0x00007ffff72f8fe0 in C_Login (session=72057594037927936, user_type=1, pin=0x7fffffffe39b "123456", pin_len=6)
    at src/pkcs11.c:451
#4  0x000055555555ef9a in ?? ()
#5  0x000055555555bec0 in ?? ()
#6  0x00007ffff78fc0b3 in __libc_start_main (main=0x55555555b420, argc=10, argv=0x7fffffffdfa8, init=<optimized out>, 
    fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffffffdf98) at ../csu/libc-start.c:308
#7  0x000055555555e78e in ?? ()
(gdb) l
152	
153	size_t twist_len(twist tstring) {
154	
155		twist_hdr *str = from_twist_to_hdr(tstring);
156	
157		size_t len = str->end - str->data;
158		return len;
159	}
160	
161	twist twist_dup(twist tstring) {
(gdb) p *str
Cannot access memory at address 0xfffffffffffffff8
(gdb) p str
$1 = (twist_hdr *) 0xfffffffffffffff8
(gdb) p tstring
$2 = (twist) 0x0
(gdb) frame 1
#1  0x00007ffff73176a5 in tpm_loadobj (ctx=0x5555555aabe0, phandle=4293479, auth=0x0, pub_data=0x0, priv_data=0x0, 
    handle=0x5555555aebc8) at src/lib/tpm.c:793
793	    size_t len = twist_len(pub_data);
(gdb) list
788	        uint32_t phandle, twist auth,
789	        twist pub_data, twist priv_data,
790	        uint32_t *handle) {
791	
792	    TPM2B_PUBLIC pub = { .size = 0 };
793	    size_t len = twist_len(pub_data);
794	
795	    size_t offset = 0;
796	    TSS2_RC rval = Tss2_MU_TPM2B_PUBLIC_Unmarshal((uint8_t *)pub_data, len, &offset, &pub);
797	    if (rval != TSS2_RC_SUCCESS) {
(gdb) frame 2
#2  0x00007ffff73106aa in session_ctx_login (ctx=0x5555555ad590, user=1, pin=0x7fffffffe39b "(redacted)", pinlen=6)
    at src/lib/session_ctx.c:285
285	    bool res = tpm_loadobj(tpm, pobj_handle, pobjauth, sealpub, sealpriv, &sealobj->handle);
(gdb) l
280	    twist sealpriv = is_user(user) ? sealobj->userpriv : sealobj->sopriv;
281	
282	    uint32_t pobj_handle = tok->pobject.handle;
283	    twist pobjauth = tok->pobject.objauth;
284	
285	    bool res = tpm_loadobj(tpm, pobj_handle, pobjauth, sealpub, sealpriv, &sealobj->handle);
286	    if (!res) {
287	        goto error;
288	    }
289

[williamcroberts]

I see what the problem is. Trying to log into a token (--pin implicitly does a user login) before the user object is set up causes this condition. You need to call inittoken and then setpin initpin, but this should still be fixed (obviously).

[williamcroberts]

FYI this was fixed on master with aabb304. I have a fix + test on 1.X for 1.3.2 release and a test on master

[williamcroberts]

Theirs actually second bug in the ERROR: step error: UNIQUE constraint failed: tokens.id. That causes the token to be free'd and thus a mutex to be freed that is currently held. Ill have a fix for this coming up to.