1769942 - infinite loop in nss/opensc after unplugging yubikey

Status: RESOLVED WORKSFORME

(NSS :: Libraries, defect)

Description

[Julien Cristau [:jcristau]]

I'm not sure if this bug belongs in nss or opensc. Before going to lunch today I removed my yubikey from the usb slot. I came back to a mostly frozen firefox, sites telling me I was offline, no network connections working. htop was showing the main thread and socket thread using lots of CPU, mostly in kernel land according to perf top.

The socket thread stack looked like this:

#0  0x00007f7c1b46687f in __GI___poll (fds=0x7f7c07c6c6c0, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007f7bdf579d7d in  () at /lib/x86_64-linux-gnu/libpcsclite.so.1
#2  0x00007f7bdf574e50 in  () at /lib/x86_64-linux-gnu/libpcsclite.so.1
#3  0x00007f7bdf5762be in SCardGetStatusChange () at /lib/x86_64-linux-gnu/libpcsclite.so.1
#4  0x00007f7bd58136b9 in  () at /lib/x86_64-linux-gnu/libopensc.so.8
#5  0x00007f7bd5813af1 in  () at /lib/x86_64-linux-gnu/libopensc.so.8
#6  0x00007f7bd57dd90a in sc_detect_card_presence () at /lib/x86_64-linux-gnu/libopensc.so.8
#7  0x00007f7bd59d2d62 in  () at /usr/lib/x86_64-linux-gnu/onepin-opensc-pkcs11.so
#8  0x00007f7bd59d37a8 in  () at /usr/lib/x86_64-linux-gnu/onepin-opensc-pkcs11.so
#9  0x00007f7bd59ccbf5 in C_GetSlotInfo () at /usr/lib/x86_64-linux-gnu/onepin-opensc-pkcs11.so
#10 0x00007f7c1b018ccf in PK11_GetSlotInfo () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#11 0x00007f7c1afd92ef in nssSlot_IsTokenPresent () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#12 0x00007f7c1afe4af1 in nssTrustDomain_FindTrustForCertificate () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#13 0x00007f7c1afdf029 in stan_GetCERTCertificate.llvm.206316787375969930 () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#14 0x00007f7c1afc2c54 in CERT_NewTempCertificate () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#15 0x00007f7c1ae11536 in ssl_DecodeResumptionToken () at /home/jcristau/firefox/nightly/firefox/libssl3.so
#16 0x00007f7c1ae1c614 in SSLExp_SetResumptionToken () at /home/jcristau/firefox/nightly/firefox/libssl3.so
#17 0x00007f7c12ac4c2d in nsNSSSocketInfo::SetResumptionTokenFromExternalCache() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#18 0x00007f7c12ac6839 in nsSSLIOLayerAddToSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, PRFileDesc*, nsISupports**, bool, unsigned int, unsigned int) ()
    at /home/jcristau/firefox/nightly/firefox/libxul.so
#19 0x00007f7c12ac6154 in nsSSLIOLayerNewSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, PRFileDesc**, nsISupports**, bool, unsigned int, unsigned int) ()
    at /home/jcristau/firefox/nightly/firefox/libxul.so
#20 0x00007f7c12acd1ee in nsSSLSocketProvider::NewSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, unsigned int, unsigned int, PRFileDesc**, nsISupports**) ()
    at /home/jcristau/firefox/nightly/firefox/libxul.so
#21 0x00007f7c1476a840 in mozilla::net::nsSocketTransport::InitiateSocket() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#22 0x00007f7c14779a3e in mozilla::net::nsSocketEvent::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#23 0x00007f7c13dbd434 in nsThread::ProcessNextEvent(bool, bool*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#24 0x00007f7c13dc11ef in NS_ProcessNextEvent(nsIThread*, bool) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#25 0x00007f7c14771090 in mozilla::net::nsSocketTransportService::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#26 0x00007f7c1477232d in non-virtual thunk to mozilla::net::nsSocketTransportService::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#27 0x00007f7c13dbd434 in nsThread::ProcessNextEvent(bool, bool*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#28 0x00007f7c13dfde34 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#29 0x00007f7c148c2d6f in MessageLoop::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#30 0x00007f7c146d78d9 in nsThread::ThreadFunc(void*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#31 0x00007f7c1b356f73 in _pt_root () at /home/jcristau/firefox/nightly/firefox/libnspr4.so
#32 0x000055fa5ac76f7e in set_alt_signal_stack_and_start(PthreadCreateParams*) ()
#33 0x00007f7c1b8ddd80 in start_thread (arg=0x7f7c07c6e640) at pthread_create.c:481
#34 0x00007f7c1b47276f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

I then plugged the yubikey back in and everything started working again.

Comment 1

[Dana Keeler (she/her) [:keeler]]

One way to tell if it's an NSS issue would be to see if the call to C_GetSlotInfo ever finishes.

Comment 2

[Julien Cristau [:jcristau]]

Thanks for the tip, I'll take a look if I see it again.

Comment 3

[John Schanck [:jschanck]]

Looks like a pcsclite issue to me. It's strange that the poll at the top of the stack has an infinite timeout. AFAICT, opensc calls SCardGetStatusChange with a finite timeout.

gsvelto: wondering if you have any thoughts, since you authored this pcsclite patch.

Comment 4

[Gabriele Svelto [:gsvelto]]

A cursory look at SCardGetStatusChange() shows that it both sends and receives message without setting a timeout so that must be one of the poll() calls you're seeing. Both MessageReceive() and MessageSend() call poll() in a loop until they've sent or received all the data. Both of them seem to break out of their respective loops in case of errors so I don't think the loop is happening in there.

Comment 5

[Julien Cristau [:jcristau]]

(In reply to Dana Keeler (she/her) (use needinfo) (:keeler for reviews) from comment #1)

One way to tell if it's an NSS issue would be to see if the call to C_GetSlotInfo ever finishes.

This happened again just now.

C_GetSlotInfo never finishes; actually card_detect from opensc never finishes, it keeps calling sc_detect_card_presence in a loop here:
https://github.com/OpenSC/OpenSC/blob/0.22.0/src/pkcs11/slot.c#L220
(got to love the comment lines 234-235)

Better stack:

#0  0x00007f8fed68b87f in __GI___poll (fds=fds@entry=0x7f8fd9e565c0, nfds=nfds@entry=1, timeout=timeout@entry=-1) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x00007f8fbabded2d in poll (__timeout=-1, __nfds=1, __fds=0x7f8fd9e565c0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:47
#2  MessageReceive (buffer_void=buffer_void@entry=0x7f8fbabe3040 <readerStates>, buffer_size=buffer_size@entry=2944, filedes=filedes@entry=413) at ./src/winscard_msg.c:478
#3  0x00007f8fbabdafb0 in getReaderStatesAndRegisterForEvents (currentContextMap=<optimized out>, currentContextMap=0x7f8fa7d6c580) at ./src/winscard_clnt.c:3572
#4  SCardGetStatusChange (hContext=<optimized out>, dwTimeout=0, rgReaderStates=0x7f8f8469f720, cReaders=1) at ./src/winscard_clnt.c:1747
#5  0x00007f8fa77536b9 in refresh_attributes (reader=0x7f8f41518e20) at ./src/libopensc/reader-pcsc.c:373
#6  0x00007f8fa7753af1 in pcsc_detect_card_presence (reader=0x7f8f41518e20) at ./src/libopensc/reader-pcsc.c:474
#7  0x00007f8fa771d90a in sc_detect_card_presence (reader=reader@entry=0x7f8f41518e20) at ./src/libopensc/sc.c:339
#8  0x00007f8fbe717d62 in card_detect (reader=reader@entry=0x7f8f41518e20) at ./src/pkcs11/slot.c:220
#9  0x00007f8fbe7187a8 in card_detect_all () at ./src/pkcs11/slot.c:427
#10 0x00007f8fbe711bf5 in C_GetSlotInfo (slotID=0, pInfo=0x7f8fd9e56970) at ./src/pkcs11/pkcs11-global.c:611
#11 0x00007f8fed23dccf in PK11_GetSlotInfo () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#12 0x00007f8fed1fe2ef in nssSlot_IsTokenPresent () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#13 0x00007f8fed209af1 in nssTrustDomain_FindTrustForCertificate () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#14 0x00007f8fed2044e0 in stan_GetCERTCertificate.llvm.10160013148166009938 () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#15 0x00007f8fed1e7ca4 in CERT_NewTempCertificate () at /home/jcristau/firefox/nightly/firefox/libnss3.so
#16 0x00007f8fed039516 in ssl_DecodeResumptionToken () at /home/jcristau/firefox/nightly/firefox/libssl3.so
#17 0x00007f8fed0445f4 in SSLExp_SetResumptionToken () at /home/jcristau/firefox/nightly/firefox/libssl3.so
#18 0x00007f8fe4cd7dbd in nsNSSSocketInfo::SetResumptionTokenFromExternalCache() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#19 0x00007f8fe4cd99c9 in nsSSLIOLayerAddToSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, PRFileDesc*, nsISupports**, bool, unsigned int, unsigned int) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#20 0x00007f8fe4cd92e4 in nsSSLIOLayerNewSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, PRFileDesc**, nsISupports**, bool, unsigned int, unsigned int) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#21 0x00007f8fe4ce02ee in nsSSLSocketProvider::NewSocket(int, char const*, int, nsIProxyInfo*, mozilla::OriginAttributes const&, unsigned int, unsigned int, PRFileDesc**, nsISupports**) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#22 0x00007f8fe69917c9 in mozilla::net::nsSocketTransport::InitiateSocket() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#23 0x00007f8fe699fbde in mozilla::net::nsSocketEvent::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#24 0x00007f8fe5fc2ce1 in nsThread::ProcessNextEvent(bool, bool*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#25 0x00007f8fe5fc746f in NS_ProcessNextEvent(nsIThread*, bool) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#26 0x00007f8fe6997f80 in mozilla::net::nsSocketTransportService::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#27 0x00007f8fe699924d in non-virtual thunk to mozilla::net::nsSocketTransportService::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#28 0x00007f8fe5fc2ce1 in nsThread::ProcessNextEvent(bool, bool*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#29 0x00007f8fe6004334 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#30 0x00007f8fe6ae8a7f in MessageLoop::Run() () at /home/jcristau/firefox/nightly/firefox/libxul.so
#31 0x00007f8fe68fe579 in nsThread::ThreadFunc(void*) () at /home/jcristau/firefox/nightly/firefox/libxul.so
#32 0x00007f8fed2e4073 in _pt_root () at /home/jcristau/firefox/nightly/firefox/libnspr4.so
#33 0x000055a8deed618e in set_alt_signal_stack_and_start(PthreadCreateParams*) ()
#34 0x00007f8fedb02d80 in start_thread (arg=0x7f8fd9e58640) at pthread_create.c:481
#35 0x00007f8fed69776f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Comment 6

[John Schanck [:jschanck]]

This looks relevant: https://github.com/OpenSC/OpenSC/commit/738588fd2b1c69794ba9ebe7bdb898486e001ecb

Comment 7

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

The severity field is not set for this bug.
:beurdouche, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 8

[Julien Cristau [:jcristau]]

I haven't seen this in a while.