Bug 1349073 - pesign: should not require coolkey
Summary: pesign: should not require coolkey
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: coolkey
Version: 24
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: Bob Relyea
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1350890 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-06-22 16:15 UTC by John Heidemann
Modified: 2017-09-01 03:21 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1350890 (view as bug list)
Environment:
Last Closed: 2017-09-01 03:21:52 UTC
Type: Bug


Attachments (Terms of Use)
partial log at time of yubikey eject (5.42 KB, text/plain)
2016-06-23 00:19 UTC, John Heidemann
no flags Details
pcscd log (473.81 KB, application/x-gzip)
2016-06-28 15:20 UTC, Patrick C. F. Ernzer
no flags Details
pcscd log after removal of coolkey RPM (19.15 KB, text/plain)
2016-07-05 19:17 UTC, Patrick C. F. Ernzer
no flags Details


Links
System ID Priority Status Summary Last Updated
Launchpad 1551897 None None None 2016-06-22 16:15:50 UTC

Description John Heidemann 2016-06-22 16:15:51 UTC
Description of problem:
pcscd and gnome-settings run with high cpu after yubikey neo removal

Version-Release number of selected component (if applicable):
pcsc-lite-1.8.15-2.fc24.x86_64
gnome-settings-daemon-3.20.1-3.fc24.x86_64

How reproducible:
Every time.

Steps to Reproduce:
1. log in to fedora 24
2. insert yubikey
3. remove yubikey
4. run top and observe gnome-settings-daemon and pcscd both running 50-70% CPU

Actual results:
See #4.
Wasted compute, oh noes!  The fan turns on!

Work-around: kill gnome-settings-daemon.
That seems to release pcscd.
As a side-effect, it resets the Gnome Shell.

Expected results:
idleness

Additional info:
Bug report for REHL7 that looks similar
https://bugzilla.redhat.com/show_bug.cgi?id=1286320
That ticket has pointers to a Ubuntu bug report
and an upstream fix with a proposed patch.

This bug is just to get Fedora 24 tagged.

Comment 1 John Heidemann 2016-06-22 16:37:06 UTC
Sigh, not so simple.

First, here's the comment from the other ticket:

This problem seems to also occur on Fedora 24.
I see both pcscd and gnome-settings running at high CPU after a Yubikey NEO is removed.

It looks like ubuntu found it in March:
https://bugs.launchpad.net/ubuntu/+source/pcsc-lite/+bug/1551897

and upstream has a fix (from the Ubuntu bug report):

https://alioth.debian.org/plugins/scmgit/cgi-bin/gitweb.cgi?p=pcsclite/CCID.git;a=commitdiff_plain;h=3c21f452543983f3625a1965ce234074cbda6865


Second, the current pcsc-lite-ccid in F24:

  pcsc-lite-ccid-1.4.23-1.fc24.x86_64

already includes the upstream fix.  

strace on gnome-settings-daemon and pcscd do not show a massive amount of busy-waiting, just stuck in a poll loop.

Not clear how to proceed.

Comment 2 Ludovic Rousseau 2016-06-22 20:52:08 UTC
I am not sure it is the same problem as in https://alioth.debian.org/plugins/scmgit/cgi-bin/gitweb.cgi?p=pcsclite/CCID.git;a=commitdiff;h=3c21f452543983f3625a1965ce234074cbda6865

In fact I am pretty sure it is NOT the same problem.

Please, can you generate pcscd logs as described in https://pcsclite.alioth.debian.org/ccid.html#support

Comment 3 John Heidemann 2016-06-23 00:19:16 UTC
I will send you the log out-of-band (I'm not sure what's in it and I'd rather not have PII posted in Bugzilla for all time).

I've attached a partial log just around time of eject.

On yubikey eject, pcscd goes into a tight loop, repeating

00000059 winscard_svc.c:351:ContextThread() Received command: CMD_GET_READERS_STATE from client 5

as fast as it can (I got 250k lines in a few seconds).

My guess is that loop is what is dragging gnome-settings-daemon down.

(When I ran it by hand to get the log, it actually busylooped by my user g-s-d and gdm's.)

Comment 4 John Heidemann 2016-06-23 00:19:45 UTC
Created attachment 1171140 [details]
partial log at time of yubikey eject

Comment 5 Ludovic Rousseau 2016-06-23 07:08:17 UTC
As I expected the problem looks like on the application side.

pcscd received a tone of requests:
00000059 winscard_svc.c:351:ContextThread() Received command: CMD_GET_READERS_STATE from client 5

This happens every ~20µs so I guess the CPU becomes quiet busy.

What smart card middleware have you configured in gnome-settings-daemon?

Another way to trace the problem at the application level is to use "PCSC API spy, third try" http://ludovicrousseau.blogspot.fr/2011/11/pcsc-api-spy-third-try.html

Comment 6 John Heidemann 2016-06-23 07:42:41 UTC
I see nothing smartcard related in gnome-settings-daemon (search on "smart" nothing in the GUI, and `rpm -qa|grep smart` => no relevant output).

If I try your libpcsc spy out, what app am I supposed to be spying on?  gnome-settings-daemon?  pcscd?

Note that since I killed it and restarted it (to get the log in comment 4), the problem has gone away.  (Maybe pcscd has gotten disconnected from my current session, and the problem will return when I logout and/or reboot?)

Comment 7 Ludovic Rousseau 2016-06-23 13:10:48 UTC
The application to spy is gnome-settings-daemon. Since if you kill it the problem stops.

It may not be easy to spy if gnome-settings-daemon is automatically started on login.

Try to check what package depends on libpcsclite1 (or maybe pcsc-lite-libs).

Comment 8 John Heidemann 2016-06-23 16:01:23 UTC
gnome-settings-daemon does not use those libraries
(ldd /usr/libexec/gnome-settings-daemon|grep sc is empty).

And FWIW, the problem returned; the respite in comment 6 went away.

Comment 12 Patrick C. F. Ernzer 2016-06-28 15:20:38 UTC
Created attachment 1173494 [details]
pcscd log

I can reproduce this already under gdm on my freshly booted F24, no need to log in to trigger the bug (although I also see it when logged in)

steps to reproduce:
1. boot up
2. ssh in as root and do
   killall pcscd ; LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee log.txt
3. plug in Yubikey
4. remove Yubikey

actual result:
pcscd and gnome-settings-daemon eat up CPU cycles

expected result:
system handles removal of a USB smart card device just fine
(as users might disconnect or put the device in power saving mode with echo 'auto' > /sys/bus/usb/devices/…/power/control )

additional info:
# rpm -qa pcsc*
pcsc-lite-ccid-1.4.23-1.fc24.x86_64
pcsc-lite-ccid-debuginfo-1.4.23-1.fc24.x86_64
pcsc-lite-1.8.15-2.fc24.x86_64
pcsc-lite-libs-1.8.15-2.fc24.x86_64
pcsc-lite-devel-1.8.15-2.fc24.x86_64
pcsc-lite-debuginfo-1.8.15-2.fc24.x86_64


I've gzipped the log.txt and renamed it (I get the same issue with a Gemalto card reader, for this test the system was booted up with the Gemalto device ansent to not pollute logs, hence log-Yubi.txt)

The Yubikey used is a
ID 1050:0116 Yubico.com Yubikey NEO(-N) OTP+U2F+CCID

Comment 13 Patrick C. F. Ernzer 2016-06-28 15:36:25 UTC
(In reply to Patrick C. F. Ernzer from comment #11)

> I'll clone for the Gemalto in a moment

done. Bug 1350890 - pcscd and gnome-settings-daemon run with high cpu after Gemalto card reader removal

Comment 14 Patrick C. F. Ernzer 2016-07-05 19:17:50 UTC
Created attachment 1176655 [details]
pcscd log after removal of coolkey RPM

After uninstalling the package coolkey (I have 2 SmartCard devices, Bug 1350890 was about the other one) I can no longer reproduce the problem.

1. clean boot
2. note that there is no pcscd running at the graphical login prompt now
3. killall pcscd ; LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee Yubi-20160705.txt #kept the killall as I grabbed this from my history)
4. plug in Yubikey
5. see the entries in tee
6. unplug the Yubikey

CPU load stays low since removal of coolkey.

Comment 15 John Heidemann 2016-07-05 23:09:52 UTC
Seems like the coolkey bug sounds like it is fixed in 1.1.0-35 (in REHL), as documented in bug #1286320.

Until that fix is available, the work-around of "rpm -e coolkey" seems good, as per comment:14.

Comment 16 Nikos Mavrogiannopoulos 2016-07-06 16:32:35 UTC
Reassigning to coolkey.

Comment 17 Nikos Mavrogiannopoulos 2016-07-06 16:36:47 UTC
*** Bug 1350890 has been marked as a duplicate of this bug. ***

Comment 18 James Ettle 2016-09-16 22:11:04 UTC
Any advance on this for F24? Latest in Koji is 1.1.0-30.fc24, so it still spins. coolkey gets pulled in by pesign, which is a BuildRequires for kernel...

Comment 19 Nikos Mavrogiannopoulos 2016-09-19 06:52:12 UTC
Shouldn't it be assigned to pesign then? There is no reason for pesign to pull coolkey.

Comment 22 Trevor Vaughan 2016-10-10 21:40:44 UTC
Just for completeness, this appears to happen with all Smart Card readers that I've tried.

Smart Cards that I have can be inserted and removed without issue but when the reader itself is removed, pcscd goes haywire.

I don't have the option of removing the coolkey package since it contains the proper identifiers for my cards.

This is on Fedora 24 with all patches to date.

Comment 23 Ludovic Rousseau 2016-10-11 08:22:12 UTC
Trevor, if the problem comes from coolkey it is normal that you have the problem with _any_ smart card reader.

Comment 24 Jakub Jelen 2017-01-06 12:45:10 UTC
Basically the same report which is happening to me quite frequently with different SC readers:

https://bugzilla.redhat.com/show_bug.cgi?id=1364917

Is really the coolkey to blame? Is it fixed in RHEL7? Should we update a coolkey in Fedora to fix it?

Comment 25 Peter Jones 2017-01-06 19:05:52 UTC
Certainly this isn't a pesign bug - it's true that pesign doesn't strictly need to pull the pkcs11 module in, but that's just triggering the bug.

I read this bug as saying pcscd is going into la-la land whenever coolkey is providing support for an HSM has been in use and gets hot-unplugged.  That sounds like a pcscd or coolkey bug no matter what else is involved in triggering it.

So I'm re-assigning this back to coolkey, though I will fix the pesign package with a "Related:" commit tag for tracking this.  That said: does this also affect other pkcs11 modules?  Can the same thing happen with opensc?

Comment 26 Fedora Update System 2017-01-06 20:49:48 UTC
pesign-0.112-5.fc24 has been submitted as an update to Fedora 24. https://bodhi.fedoraproject.org/updates/FEDORA-2017-eb22571e6a

Comment 27 Fedora Update System 2017-01-06 20:50:53 UTC
pesign-0.112-5.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-31e2f4a0ec

Comment 28 Fedora Update System 2017-01-08 01:19:28 UTC
pesign-0.112-5.fc24 has been pushed to the Fedora 24 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-eb22571e6a

Comment 29 Fedora Update System 2017-01-08 02:21:38 UTC
pesign-0.112-5.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-31e2f4a0ec

Comment 30 Fedora End Of Life 2017-07-25 21:12:39 UTC
This message is a reminder that Fedora 24 is nearing its end of life.
Approximately 2 (two) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 24. 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 '24'.

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 24 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 31 Fedora End Of Life 2017-08-08 14:57:54 UTC
Fedora 24 changed to end-of-life (EOL) status on 2017-08-08. Fedora 24 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 32 Fedora Update System 2017-08-10 18:34:58 UTC
pesign-0.112-6.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-8976ad052b

Comment 33 Fedora Update System 2017-08-12 01:28:28 UTC
pesign-0.112-6.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-8976ad052b

Comment 34 Fedora Update System 2017-08-15 18:45:30 UTC
pesign-0.112-20.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-8976ad052b

Comment 35 Fedora Update System 2017-08-18 21:52:20 UTC
pesign-0.112-20.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-8976ad052b

Comment 36 Fedora Update System 2017-09-01 03:21:52 UTC
pesign-0.112-20.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.


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