Bug 1173279 - gnome-keyring-pkcs11 does not work reliably with Firefox
Summary: gnome-keyring-pkcs11 does not work reliably with Firefox
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: gnome-keyring
Version: 25
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Matthias Clasen
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: PKCS11 1520268
TreeView+ depends on / blocked
 
Reported: 2014-12-11 19:57 UTC by David Woodhouse
Modified: 2022-11-03 03:11 UTC (History)
8 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2017-12-12 10:13:06 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
pkcs11-spy output (2.63 MB, text/plain)
2014-12-11 19:57 UTC, David Woodhouse
no flags Details
Handle mutiple connections from the same client (3.86 KB, patch)
2014-12-12 11:35 UTC, David Woodhouse
no flags Details | Diff


Links
System ID Private Priority Status Summary Last Updated
Mozilla Foundation 1110233 0 -- RESOLVED Firefox does not consistently work with CKF_PROTECTED_AUTHENTICATION_PATH 2020-09-14 13:48:47 UTC

Description David Woodhouse 2014-12-11 19:57:47 UTC
Created attachment 967371 [details]
pkcs11-spy output

I filed this as a Firefox bug https://bugzilla.mozilla.org/show_bug.cgi?id=1110233 but now I'm not so sure.

The GKR module *sometimes* works with Firefox and sometimes doesn't. I haven't worked out what causes the difference. Sometimes it's nice...

5426: C_OpenSession
2014-12-11 19:42:21.233
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc8f
Returned:  0 CKR_OK

5427: C_SignInit
2014-12-11 19:42:21.233
[in] hSession = 0xc8f
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  0 CKR_OK

... and sometimes it's nasty...

6151: C_OpenSession
2014-12-11 19:42:30.231
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc92
Returned:  0 CKR_OK

6152: C_SignInit
2014-12-11 19:42:30.231
[in] hSession = 0xc92
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  257 CKR_USER_NOT_LOGGED_IN


I can hit shift-reload to reload a page in Firefox which wants a cert. Sometimes it works, and sometimes it just gives me an error that the PKCS#11 token isn't logged in.

Full pkcs11-spy log attached.

Comment 1 David Woodhouse 2014-12-11 21:21:38 UTC
I think GKR is forgetting its login status when it shouldn't. Here's an edited version of the log...

25: C_OpenSession
2014-12-11 19:42:17.061
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc8b
Returned:  0 CKR_OK

2380: C_Login
2014-12-11 19:42:17.932
[in] hSession = 0xc8b
[in] userType = CKU_USER
[in] pPin[ulPinLen] NULL [size : 0x0 (0)]
Returned:  0 CKR_OK

5426: C_OpenSession
2014-12-11 19:42:21.233
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc8f
Returned:  0 CKR_OK

5427: C_SignInit
2014-12-11 19:42:21.233
[in] hSession = 0xc8f
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  0 CKR_OK

5430: C_CloseSession
2014-12-11 19:42:21.555
[in] hSession = 0xc8f
Returned:  0 CKR_OK

5611: C_OpenSession
2014-12-11 19:42:22.457
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc90
Returned:  0 CKR_OK

5612: C_SignInit
2014-12-11 19:42:22.457
[in] hSession = 0xc90
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  0 CKR_OK

5615: C_CloseSession
2014-12-11 19:42:22.720
[in] hSession = 0xc90
Returned:  0 CKR_OK

5759: C_OpenSession
2014-12-11 19:42:22.975
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc91
Returned:  0 CKR_OK

5760: C_SignInit
2014-12-11 19:42:22.975
[in] hSession = 0xc91
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  0 CKR_OK

5763: C_CloseSession
2014-12-11 19:42:23.242
[in] hSession = 0xc91
Returned:  0 CKR_OK

5971: C_GetSessionInfo
2014-12-11 19:42:29.786
[in] hSession = 0xc8b
[out] pInfo: 
      slotID:                  18
      state:                  '           CKS_RO_USER_FUNCTIONS'
      flags:                   40000004
        CKF_SERIAL_SESSION               
      ulDeviceError:           0
Returned:  0 CKR_OK

6151: C_OpenSession
2014-12-11 19:42:30.231
[in] slotID = 0x12
[in] flags = 0x4
pApplication=0x7f9cb3b7a000
Notify=0x3ef1e53340
[out] *phSession = 0xc92
Returned:  0 CKR_OK

6152: C_SignInit
2014-12-11 19:42:30.231
[in] hSession = 0xc92
pMechanism->type=CKM_RSA_PKCS                 
[in] hKey = 0x13f
Returned:  257 CKR_USER_NOT_LOGGED_IN


This is wrong. Session 0xc8b still exists, and the login state should never have been forgotten. And in fact...

6154: C_GetSessionInfo
2014-12-11 19:42:33.581
[in] hSession = 0xc8b
[out] pInfo: 
      slotID:                  18
      state:                  '           CKS_RO_USER_FUNCTIONS'
      flags:                   40000004
        CKF_SERIAL_SESSION               
      ulDeviceError:           0
Returned:  0 CKR_OK

Comment 2 David Woodhouse 2014-12-11 22:20:42 UTC
It looks like a threading issue. Firefox is invoking the functions of gnome-keyring-pkcs11.so in parallel from different threads, which means we end up creating a *new* connection in call_lookup() because the original one was busy and not available in the pool.

AFAICT it's allowed to do this as long as it doesn't access the same *session* from multiple threads.

How is the design here supposed to work? Is it just a fundamental error that we allow multiple connections to the dæmon, and we should fix it to use just one and make threads wait? Or is there supposed to be some way to *tell* the dæmon that all these connections are in fact from the *same* client?

Comment 3 David Woodhouse 2014-12-11 22:28:56 UTC
This makes the problem stop happening by ensuring that only one thread at a time can make calls. Obviously not a correct fix:

--- a/pkcs11/rpc-layer/gkm-rpc-module.c
+++ b/pkcs11/rpc-layer/gkm-rpc-module.c
@@ -321,7 +321,7 @@ call_lookup (CallState **ret)
                        --n_call_state_pool;
                }
 
-       pthread_mutex_unlock (&call_state_mutex);
+//     pthread_mutex_unlock (&call_state_mutex);
 
        if (cs == NULL) {
                cs = calloc(1, sizeof (CallState));
@@ -615,7 +615,7 @@ call_done (CallState *cs, CK_RV ret)
        if (ret != CKR_DEVICE_ERROR && ret != CKR_DEVICE_REMOVED && cs->socket != -1) {
 
                /* Try and stash it away for later use */
-               pthread_mutex_lock (&call_state_mutex);
+//             pthread_mutex_lock (&call_state_mutex);
 
                        if (n_call_state_pool < MAX_CALL_STATE_POOL) {
                                cs->call_status = CALL_READY;

Comment 4 Stef Walter 2014-12-12 07:50:58 UTC
Thanks for diagnosing this.

FWIW, I'd like to remove gnome-keyring-pkcs11.so from gnome-keyring this cycle. 

It was an interesting project, but it's irresponsible of me to leave it in such a state when solid alternatives like OpenHSM exist, and remoting now exists (and is being actively worked on) in p11-kit.

Comment 5 David Woodhouse 2014-12-12 11:35:15 UTC
Created attachment 967578 [details]
Handle mutiple connections from the same client

(In reply to Stef Walter from comment #4)
> Thanks for diagnosing this.
> 
> FWIW, I'd like to remove gnome-keyring-pkcs11.so from gnome-keyring this
> cycle. 

That's a shame, as it's nice to have a writeable token that's available by default. Making SoftHSM (or NSS softokn) work as nicely will take more effort.

Here's a patch which should fix it in the meantime. For all connections from the same {pid,uid}, we now use the same CK_G_APPLICATION — and thus the same applicationId, which is important. I've also changed the pointer we use for the applicationData, but it doesn't look like that's actually used anywhere.

Comment 6 David Woodhouse 2015-04-27 13:04:01 UTC
It looks like PKCS#11 is still present in 3.16 — thankfully, since we don't have a drop-in replacement for it. And yet this patch isn't applied.

Comment 7 Nikos Mavrogiannopoulos 2015-06-23 11:05:33 UTC
Hello Matthias, is there a reason the patch wasn't applied?

Comment 8 Stef Walter 2015-06-23 11:23:03 UTC
Seems like data is accessed outside the clients_mutex lock. A simple accessor function which does lock, copy, unlock ... might be appropriate.

Comment 9 David Woodhouse 2015-06-23 11:42:12 UTC
(In reply to Stef Walter from comment #8)
> Seems like data is accessed outside the clients_mutex lock. A simple
> accessor function which does lock, copy, unlock ... might be appropriate.

Only while a refcount is held on the ClientInstance, which means it cannot go away. As discussed in IRC, I've changed the name of the 'users' variable to 'refcount' and committed it to gkr master:

https://git.gnome.org/browse/gnome-keyring/commit/?id=3c0555325

Should I commit to the 3.16 branch too?

Comment 10 Stef Walter 2015-06-23 11:45:09 UTC
David, I'm a little more concerned about 3.16 upstream. But you would like to own the releases on the 3.16 branch and troubleshoot any fallout, then I'll hand that over to you and I'd be fine with pushing that in there.

Comment 11 David Woodhouse 2015-06-23 13:37:35 UTC
I concede I've never actually worked out how to do GNOME releases. How about I just apply the patch to the Fedora 22 package and close the bug, then take responsibility for *that*? Although I'm quite keen not to also volunteer for bug 1215270 at the same time :)

Comment 12 Fedora End Of Life 2016-07-19 12:31:34 UTC
Fedora 22 changed to end-of-life (EOL) status on 2016-07-19. Fedora 22 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 13 Jan Kurik 2016-07-26 04:41:02 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 25 development cycle.
Changing version to '25'.

Comment 14 Fedora End Of Life 2017-11-16 18:52:57 UTC
This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '25'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 25 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 15 Fedora End Of Life 2017-12-12 10:13:06 UTC
Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.

Comment 16 beehivesteeth 2022-11-03 03:11:14 UTC Comment hidden (spam)

Note You need to log in before you can comment on or make changes to this bug.