1610644 - be more efficient about finding new certificates for users who have 1000s of client certificates

Status: RESOLVED FIXED

(Core :: Security: PSM, enhancement, P1)

Description

[nonbirithm]

Attachment: 2020-01-17 11_40_36-Error.png

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.117 Safari/537.36

Steps to reproduce:

1. Go to login.microsoft.com.
2. Enter an account that requires smartcard authentication.
3. Choose "Use a smartcard or PIN" on the dialog that opens after signing in with a password.

Actual results:

This error appears, and there is no choice of certificates/smartcard to use like there is in Chrome.

An error occurred
No valid client certificate found in the request. No valid certificates found in the user's certificate store. Please try again choosing a different authentication method.

Expected results:

There should have been a popup menu displaying the list of certificates to use, and I should be able to select my smartcard from them.

Comment 1

[nonbirithm]

Also reported at https://github.com/webcompat/web-bugs/issues/47735. They asked me to file a bug report here.

Comment 2

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

If you use Nightly (https://www.mozilla.org/en-US/firefox/channel/desktop/) and set the preference security.osclientcerts.autoload to true in about:config, does it work?

Comment 3

[nonbirithm]

I enabled the option and tried to login. At the point where the certificate list should show up the browser froze (with the Not Responding title) although the CSS animation kept updating. Then I force closed the process and tried to disable the option and this caused an immediate crash, so it seems I can't disable it. This is on the latest Nightly.

Comment 4

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Are there any crash reports in about:crashes? Can you link them here?

Comment 5

[nonbirithm]

No, there are no crash reports that appear there.

Comment 6

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

When Firefox freezes, can you use Process Explorer to see what's on Firefox's call stack?

Comment 7

[nonbirithm]

Attachment: 2020-01-27 18_05_45-firefox.exe_36288 Properties.png

Comment 8

[nonbirithm]

Attachment: 2020-01-27 18_06_11-Stack for thread 41388.png

Comment 9

[nonbirithm]

Attachment: 2020-01-27 18_05_56-Stack for thread 28468.png

Comment 10

[nonbirithm]

I attached the stack information for Firefox. Hopefully this is what you need.

Also, I left an instance of Nightly running overnight when it hanged at the certificate selection stage and eventually it succeeded and showed the list of certificates. However it was missing the certificate I use for smartcard authentication, so I couldn't proceed.

Comment 11

[nonbirithm]

Attachment: 2020-01-28 16_45_39-Stack for thread 4620.png

Comment 12

[nonbirithm]

Attachment: 2020-01-28 16_46_38-Stack for thread 15596.png

Comment 13

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Thanks! Can you do that again, but only with threads that are in osclientcerts.dll?

Comment 14

[nonbirithm]

Attachment: 2020-01-29 14_14_27-Stack for thread 41884.png

This is the stack during the Firefox hang.

Comment 15

[nonbirithm]

Attachment: 2020-01-29 14_23_27-Stack for thread 41884.png

This is the stack once the message window is reached.

Comment 16

[nonbirithm]

Also if I choose any certificate at the certificate list and proceed, it will say the page load timed out as if it was a network timeout issue, probably because it takes so long to load the window.

Comment 17

[nonbirithm]

I checked again and it seems like the stack is changing very frequently, it seems like it's doing a lot of work in a loop.

Comment 18

[nonbirithm]

Attachment: 2020-01-29 14_31_10-Stack for thread 41884.png

Comment 19

[nonbirithm]

Attachment: 2020-01-29 14_31_44-Stack for thread 41884.png

Comment 20

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Thanks! Does it behave differently if you use Firefox 73?

Comment 21

[nonbirithm]

No, there is no difference in behavior.

Comment 22

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Can you run Firefox in a terminal with the environment variable RUST_LOG set to osclientcerts=debug and attach the debugging output here as a text file?

Comment 23

[nonbirithm]

Attachment: firefox.log

Attached. I could only capture 9999 lines since I was unable to redirect the output to a file (using -attach-console) and that's the maximum buffer size the Powershell settings permits.

Also I should mention that capturing the debug output was way harder than I thought it would be. First the output wouldn't even show up unless I used a specific shortcut to the Powershell prompt (it doesn't appear in ISE). The program doesn't seem to write to stdout when I use -attach-console even though it prints everything so I couldn't redirect it to a file in cmd or PowerShell, and it ignored set RUST_LOG=osclientcerts=debug unless I set it in System Preferences (probably because it spawns a new process with a different env). It also seemed to ignore -foreground and kept running in the background anyway. Setting MOZ_LOG_FILE ends up in all the logs being empty even though it still prints everything on the console.

Comment 24

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Thanks - can you try again with RUST_LOG set to osclientcerts/found?

Comment 25

[nonbirithm]

Attachment: firefox.2.log

Attached. I had to use osclientcerts=debug/found to get any output.

Comment 26

[BugBot [:suhaib / :marco/ :calixte]]

The priority flag is not set for this bug.
:keeler, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 27

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Thanks! It looks like we need to re-work how we look for new client certs.

Comment 28

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Attachment: bug 1610644 - search for new client certificates/keys in osclientcerts no more than once every 3 seconds r?kjacobs

Before this, every time NSS wanted to open a new session (C_OpenSession),
osclientcerts would look for new client certificates/keys in the OS store. It
turns out, NSS wants to open new sessions often, so this was slow. This patch
adds a timestamp to the manager and ensures that it searches for new objects no
more than once every 3 seconds.

Additionally, this patch adds the optimization that if NSS tries to search for
PKCS#11 objects with attributes that osclientcerts doesn't support,
osclientcerts returns an empty search early, rather than enumerating every
object and finding no matches.

In the future we may need to be smarter about how we match objects during
searches. Rather than iterating through every object, we could build lookup
tables that would be much more time efficient.

Comment 29

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/254080484266
search for new client certificates/keys in osclientcerts no more than once every 3 seconds r=kjacobs

Comment 30

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/254080484266

Comment 31

[nonbirithm]

Thanks for fixing this.

Comment 32

[Dana Keeler (she/her) (use needinfo) [:keeler] (on leave)]

Sure thing - is the latest Nightly working for you?

Comment 33

[nonbirithm]

The issue with the dialog taking a long time to load is fixed, but in the dialog the physical smartcard certificate I use does not appear. I filed a new bug for this issue. https://bugzilla.mozilla.org/show_bug.cgi?id=1617000